Error in NSC connecting to NSE when the pods get rescheduled to a different kubernetes worker node

Expected Behavior

When the pods running the nsc and nse sidecar containers gets rescheduled to a different kubernetes node, they should be able to connect.
Current Behavior

When the pods gets rescheduled to a different kubernetes node due to a node failure of the initial hosted node, the connection breaks and NSC starts throwing "NSM:(7.1.5)" error. i.e. it still tries to establish connection to the old node where the pod was initially hosted and throws a node not found error.
Failure Information (for bugs)

Steps to Reproduce

Use the topology example and create a two router topology between quagga devices
Make one of the kubernetes nodes to fail, so that the pod gets rescheduled to a different node in the cluster
NSC still tries to connect to the old node and not found error is thrown

Context

Kubernetes Version:
Client Version: version.Info{Major:"1", Minor:"17", GitVersion:"v1.17.0", GitCommit:"70132b0f130acc0bed193d9ba59dd186f0e634cf", GitTreeState:"clean", BuildDate:"2019-12-07T21:20:10Z", GoVersion:"go1.13.4", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"18+", GitVersion:"v1.18.0-alpha.2", GitCommit:"a7b4459cd1cf89420e2370ae5d067fc5ad6629ba", GitTreeState:"clean", BuildDate:"2020-01-21T10:43:51Z", GoVersion:"go1.13.6", Compiler:"gc", Platform:"linux/amd64"}
Running this in an AKS cluster.

Failure Logs
kubectl logs venkissue01-5d46849664-zhhhp nsc-sidecar
time="2020-05-27T22:19:10Z" level=info msg="Starting nsc-sidecar..."

time="2020-05-27T22:19:10Z" level=info msg="CLIENT_NETWORK_SERVICE not found."
time="2020-05-27T22:19:10Z" level=info msg="ENDPOINT_LABELS not found."
time="2020-05-27T22:19:10Z" level=info msg="CLIENT_LABELS not found."
time="2020-05-27T22:19:10Z" level=info msg="NSC_INTERFACE_NAME not found."
time="2020-05-27T22:19:10Z" level=info msg="MECHANISM_TYPE not found."
time="2020-05-27T22:19:10Z" level=info msg="IP_ADDRESS not found."
time="2020-05-27T22:19:10Z" level=info msg="POD_NAME not found."
time="2020-05-27T22:19:10Z" level=info msg="NSM_NAMESPACE not found."
time="2020-05-27T22:19:10Z" level=info msg="ROUTES not found."
time="2020-05-27T22:19:10Z" level=info msg="Creating logger from config: &{nsm-init@venkissue01-5d46849664-zhhhp false false [] 0xc000138400 0xc0000b8600   }"
2020/05/27 22:19:10 Initializing logging reporter
time="2020-05-27T22:19:10Z" level=info msg="==--> RequestNetworkService() span:51afe4f9448396f0:51afe4f9448396f0:0:1"
time="2020-05-27T22:19:10Z" level=info msg="ENDPOINT_NETWORK_SERVICE not found."
time="2020-05-27T22:19:10Z" level=info msg="CLIENT_NETWORK_SERVICE not found."
time="2020-05-27T22:19:10Z" level=info msg="ENDPOINT_LABELS not found."
time="2020-05-27T22:19:10Z" level=info msg="CLIENT_LABELS not found."
time="2020-05-27T22:19:10Z" level=info msg="NSC_INTERFACE_NAME not found."
time="2020-05-27T22:19:10Z" level=info msg="MECHANISM_TYPE not found."
time="2020-05-27T22:19:10Z" level=info msg="IP_ADDRESS not found."
time="2020-05-27T22:19:10Z" level=info msg="POD_NAME not found."
time="2020-05-27T22:19:10Z" level=info msg="NSM_NAMESPACE not found."
time="2020-05-27T22:19:10Z" level=info msg="ROUTES not found."
time="2020-05-27T22:19:10Z" level=info msg="NSM_NAMESPACE not found."
time="2020-05-27T22:19:10Z" level=warning msg="global opentracer is already initialized"
time="2020-05-27T22:19:10Z" level=info msg="Creating logger from config: &{nsm-client@venkissue01-5d46849664-zhhhp false false [] 0xc000138d00 0xc0000b8b40   }"
2020/05/27 22:19:10 Initializing logging reporter
time="2020-05-27T22:19:12Z" level=info msg="nsm: connection to nsm server on socket: /var/lib/networkservicemesh/nsm.server.io.sock succeeded."
time="2020-05-27T22:19:12Z" level=info msg="==----> nsmClient.Connect() span:51afe4f9448396f0:5a79ed213dccb121:51afe4f9448396f0:1"
time="2020-05-27T22:19:12Z" level=info msg="Initiating an outgoing connection." operation=nsmClient.Connect span="51afe4f9448396f0:5a79ed213dccb121:51afe4f9448396f0:1"
time="2020-05-27T22:19:12Z" level=info msg=">><<---- Selected mechanism={"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"Ethernet3","netnsInode":"4026532223","socketfile":"Ethernet3/memif.sock"}} span=51afe4f9448396f0:5a79ed213dccb121:51afe4f9448396f0:1"
time="2020-05-27T22:19:12Z" level=info msg="==------> nsmClient.Connect.attempt:0() span:51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
time="2020-05-27T22:19:12Z" level=info msg="Requesting connection:<network_service:"venkissuetopo01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-173" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"Ethernet3" > labels:<key:"podName" value:"venkissue01-5d46849664-zhhhp" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"Ethernet3" > parameters:<key:"netnsInode" value:"4026532223" > parameters:<key:"socketfile" value:"Ethernet3/memif.sock" > > " operation="nsmClient.Connect.attempt:0" span="51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
time="2020-05-27T22:19:12Z" level=info msg=">><<-------- /networkservice.NetworkService/Request()="" span=51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
time="2020-05-27T22:19:12Z" level=info msg=">><<-------- request={"connection":{"network_service":"venkissuetopo01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-173","namespace":"default","peerif":"Ethernet3","podName":"venkissue01-5d46849664-zhhhp"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"Ethernet3","netnsInode":"4026532223","socketfile":"Ethernet3/memif.sock"}}]} span=51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
2020/05/27 22:19:14 Reporting span 51afe4f9448396f0:6cc9fb43a3117cca:66b50b7c19affb6e:1
time="2020-05-27T22:19:14Z" level=info msg=">><<-------- response={} span=51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
time="2020-05-27T22:19:14Z" level=error msg=">><<------ error=rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span=51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
time="2020-05-27T22:19:14Z" level=error msg="nsm client: Failed to connect rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found. Retry attempts: 10 Delaying: 5s" operation="nsmClient.Connect.attempt:0" span="51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1"
2020/05/27 22:19:14 Reporting span 51afe4f9448396f0:66b50b7c19affb6e:5a79ed213dccb121:1
time="2020-05-27T22:19:19Z" level=info msg="==------> nsmClient.Connect.attempt:1() span:51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
time="2020-05-27T22:19:19Z" level=info msg="Requesting connection:<network_service:"venkissuetopo01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-173" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"Ethernet3" > labels:<key:"podName" value:"venkissue01-5d46849664-zhhhp" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"Ethernet3" > parameters:<key:"netnsInode" value:"4026532223" > parameters:<key:"socketfile" value:"Ethernet3/memif.sock" > > " operation="nsmClient.Connect.attempt:1" span="51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
time="2020-05-27T22:19:19Z" level=info msg=">><<-------- /networkservice.NetworkService/Request()="" span=51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
time="2020-05-27T22:19:19Z" level=info msg=">><<-------- request={"connection":{"network_service":"venkissuetopo01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-173","namespace":"default","peerif":"Ethernet3","podName":"venkissue01-5d46849664-zhhhp"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"Ethernet3","netnsInode":"4026532223","socketfile":"Ethernet3/memif.sock"}}]} span=51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
2020/05/27 22:19:19 Reporting span 51afe4f9448396f0:8309891b108d2f6:6cfc860c5251dedb:1
time="2020-05-27T22:19:19Z" level=info msg=">><<-------- response={} span=51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
time="2020-05-27T22:19:19Z" level=error msg=">><<------ error=rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span=51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
time="2020-05-27T22:19:19Z" level=error msg="nsm client: Failed to connect rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found. Retry attempts: 9 Delaying: 5s" operation="nsmClient.Connect.attempt:1" span="51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1"
2020/05/27 22:19:19 Reporting span 51afe4f9448396f0:6cfc860c5251dedb:5a79ed213dccb121:1
2020/05/27 22:19:19 ERROR: error when flushing the buffer: write udp <IP_ADDRESS>:43910-><IP_ADDRESS>:6831: write: connection refused
time="2020-05-27T22:19:24Z" level=info msg="==------> nsmClient.Connect.attempt:2() span:51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
time="2020-05-27T22:19:24Z" level=info msg="Requesting connection:<network_service:"venkissuetopo01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-173" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"Ethernet3" > labels:<key:"podName" value:"venkissue01-5d46849664-zhhhp" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"Ethernet3" > parameters:<key:"netnsInode" value:"4026532223" > parameters:<key:"socketfile" value:"Ethernet3/memif.sock" > > " operation="nsmClient.Connect.attempt:2" span="51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
time="2020-05-27T22:19:24Z" level=info msg=">><<-------- /networkservice.NetworkService/Request()="" span=51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
time="2020-05-27T22:19:24Z" level=info msg=">><<-------- request={"connection":{"network_service":"venkissuetopo01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-173","namespace":"default","peerif":"Ethernet3","podName":"venkissue01-5d46849664-zhhhp"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"Ethernet3","netnsInode":"4026532223","socketfile":"Ethernet3/memif.sock"}}]} span=51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
2020/05/27 22:19:24 Reporting span 51afe4f9448396f0:2b6fc9a6d44eba8e:1ce901e0aa0548ad:1
time="2020-05-27T22:19:24Z" level=info msg=">><<-------- response={} span=51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
time="2020-05-27T22:19:24Z" level=error msg=">><<------ error=rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span=51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
time="2020-05-27T22:19:24Z" level=error msg="nsm client: Failed to connect rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found. Retry attempts: 8 Delaying: 5s" operation="nsmClient.Connect.attempt:2" span="51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1"
2020/05/27 22:19:24 Reporting span 51afe4f9448396f0:1ce901e0aa0548ad:5a79ed213dccb121:1
time="2020-05-27T22:19:29Z" level=info msg="==------> nsmClient.Connect.attempt:3() span:51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
time="2020-05-27T22:19:29Z" level=info msg="Requesting connection:<network_service:"venkissuetopo01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-173" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"Ethernet3" > labels:<key:"podName" value:"venkissue01-5d46849664-zhhhp" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"Ethernet3" > parameters:<key:"netnsInode" value:"4026532223" > parameters:<key:"socketfile" value:"Ethernet3/memif.sock" > > " operation="nsmClient.Connect.attempt:3" span="51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
time="2020-05-27T22:19:29Z" level=info msg=">><<-------- /networkservice.NetworkService/Request()="" span=51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
time="2020-05-27T22:19:29Z" level=info msg=">><<-------- request={"connection":{"network_service":"venkissuetopo01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-173","namespace":"default","peerif":"Ethernet3","podName":"venkissue01-5d46849664-zhhhp"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"Ethernet3","netnsInode":"4026532223","socketfile":"Ethernet3/memif.sock"}}]} span=51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
2020/05/27 22:19:29 Reporting span 51afe4f9448396f0:60ca7d98ffb81b73:21d84aa64d973a05:1
time="2020-05-27T22:19:29Z" level=info msg=">><<-------- response={} span=51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
time="2020-05-27T22:19:29Z" level=error msg=">><<------ error=rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span=51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
time="2020-05-27T22:19:29Z" level=error msg="nsm client: Failed to connect rpc error: code = Unknown desc = NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found. Retry attempts: 7 Delaying: 5s" operation="nsmClient.Connect.attempt:3" span="51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1"
2020/05/27 22:19:29 Reporting span 51afe4f9448396f0:21d84aa64d973a05:5a79ed213dccb121:1

I'm a little confused... Pods don't get 'moved' to new Nodes in my experience.  You can have a deployment and have one Pod go away and another start.  But they never 'move'.  Could you provide more detail?

Sorry, by pod moving I meant, one goes away and another starts. I am using cluster autoscaler with AKS cluster. I am noticing "kernel panic" issue and the node keeps restarting. After sometime the cluster autoscaler removed that node and creates a new node and a new pod gets scheduled in the new node created by autoscaler and then I start seeing this issue. I am noticing the kernel panic happen when it tries to create a VxLAN link, but couldn't get proper logs as the node keeps restarting.

I could only grab these logs when the kernel panic happens
kubectl logs nsmgr-mz82x --namespace=nsm-system nsmd
time="2020-05-29T07:41:47Z" level=info msg="Starting nsmd..."
time="2020-05-29T07:41:47Z" level=info msg="Version: c1b19595"
time="2020-05-29T07:41:47Z" level=info msg="All env variables:"
time="2020-05-29T07:41:47Z" level=info msg="JAEGER_AGENT_PORT=6831"
time="2020-05-29T07:41:47Z" level=info msg="TRACER_ENABLED=true"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_PORT=tcp://<IP_ADDRESS>:443"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_SERVICE_PORT=443"
time="2020-05-29T07:41:47Z" level=info msg="HOSTNAME=nsmgr-mz82x"
time="2020-05-29T07:41:47Z" level=info msg="SHLVL=1"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_PORT=tcp://<IP_ADDRESS>:443"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_SERVICE_PORT=443"
time="2020-05-29T07:41:47Z" level=info msg="HOME=/root"
time="2020-05-29T07:41:47Z" level=info msg="INSECURE=true"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_PORT_443_TCP_ADDR=<IP_ADDRESS>"
time="2020-05-29T07:41:47Z" level=info msg="PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_PORT_443_TCP_PORT=443"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_PORT_443_TCP_PROTO=tcp"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_PORT_443_TCP_ADDR=<IP_ADDRESS>"
time="2020-05-29T07:41:47Z" level=info msg="ENTRY=nsmd"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_PORT_443_TCP_PORT=443"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_PORT_443_TCP_PROTO=tcp"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_PORT_443_TCP=tcp://<IP_ADDRESS>:443"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_SERVICE_PORT_HTTPS=443"
time="2020-05-29T07:41:47Z" level=info msg="JAEGER_AGENT_HOST=jaeger.nsm-system"
time="2020-05-29T07:41:47Z" level=info msg="KUBERNETES_SERVICE_HOST=<IP_ADDRESS>"
time="2020-05-29T07:41:47Z" level=info msg="PWD=/"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_PORT_443_TCP=tcp://<IP_ADDRESS>:443"
time="2020-05-29T07:41:47Z" level=info msg="NSM_ADMISSION_WEBHOOK_SVC_SERVICE_HOST=<IP_ADDRESS>"
time="2020-05-29T07:41:47Z" level=info msg="Creating logger from config: &{nsmd@nsmgr-mz82x false false [] 0xc000172000 0xc0000700c0   }"
time="2020-05-29T07:41:47Z" level=error msg="ERROR: cannot init Jaeger: lookup jaeger.nsm-system on <IP_ADDRESS>:53: no such host\n"
time="2020-05-29T07:41:47Z" level=info msg="==--> nsmd.server() span:{}"
time="2020-05-29T07:41:47Z" level=info msg=">><<-- tracing.init-complete=38.9659ms span={}"
time="2020-05-29T07:41:47Z" level=info msg="==----> nsm-server-start() span:{}"
time="2020-05-29T07:41:47Z" level=info msg="Starting NSM server" operation=nsm-server-start span="{}"
time="2020-05-29T07:41:47Z" level=info msg="==------> NewServer() span:{}"
time="2020-05-29T07:41:47Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:47Z" level=info msg="Starting NSM gRPC server listening on socket: /var/lib/networkservicemesh/nsm.io.sock"
time="2020-05-29T07:41:47Z" level=info msg="==------> set-local-nsm() span:{}"
time="2020-05-29T07:41:47Z" level=info msg="Requesting NsmRegistryClient..." span="{}"
time="2020-05-29T07:41:47Z" level=info msg="==----------> initRegistryClient() span:{}"
time="2020-05-29T07:41:47Z" level=info msg="Waiting for liveness probe: tcp:<IP_ADDRESS>:5000"
time="2020-05-29T07:41:47Z" level=info msg=">><<-- GRPC->/nsmdapi.NSMD/EnumConnection()="" span={}"
time="2020-05-29T07:41:47Z" level=info msg=">><<-- request={} span={}"
time="2020-05-29T07:41:47Z" level=info msg=">><<-- response={} span={}"
time="2020-05-29T07:41:50Z" level=info msg="Registry port now available, attempting to connect..." operation=initRegistryClient span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Successfully connected to <IP_ADDRESS>:5000" operation=initRegistryClient span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<------ url=<IP_ADDRESS>:5001 span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- /registry.NsmRegistry/RegisterNSM()="" span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- request={"url":"<IP_ADDRESS>:5001"} span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- response={"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"} span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- /registry.NsmRegistry/GetEndpoints()="" span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- request={} span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<-------- response={"network_service_endpoints":[{"name":"topoex01wzz6f","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example01","networkservicename":"topoex01"},"state":"RUNNING"},{"name":"venkissuetopo016vddh","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"},{"name":"venkissuetopo01bg4fx","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"},{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}]} span={}"
time="2020-05-29T07:41:50Z" level=info msg="Setting local NSM name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" "
time="2020-05-29T07:41:50Z" level=info msg=">><<---- registered-endpoints={"network_service_endpoints":[{"name":"topoex01wzz6f","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example01","networkservicename":"topoex01"},"state":"RUNNING"},{"name":"venkissuetopo016vddh","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"},{"name":"venkissuetopo01bg4fx","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"},{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}]} span={}"
time="2020-05-29T07:41:50Z" level=info msg="Connecting to nsmd on socket: /var/lib/networkservicemesh/nsm.io.sock..."
time="2020-05-29T07:41:50Z" level=info msg="Requesting nsmd for client connection..."
time="2020-05-29T07:41:50Z" level=info msg="NSM gRPC socket: /var/lib/networkservicemesh/nsm.io.sock is operational" operation=nsm-server-start span="{}"
time="2020-05-29T07:41:50Z" level=info msg="create monitor servers" operation=nsm-server-start span="{}"
time="2020-05-29T07:41:50Z" level=info msg="CrossConnect - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="RemoteConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="==------> restore() span:{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<------ delete.client.registry=false span={}"
time="2020-05-29T07:41:50Z" level=info msg="Values: [CLE nsm-17]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [CLE nsm-27]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [CLE nsm-13]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [CLE nsm-16]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [CLE nsm-15]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [NSE venkissuetopo016vddh nsm-15 ChUKD3Zlbmtpc3N1ZXRvcG8wMRICSVASPwohazhzLWFnZW50cG9vbC0yNDM3Njk5Ny12bXNzMDAwMDE3EhExMC4yNDAuMC4xMjk6NTAwMSIHUlVOTklORxqVAQoUdmVua2lzc3VldG9wbzAxNnZkZGgSAklQGg92ZW5raXNzdWV0b3BvMDEiIWs4cy1hZ2VudHBvb2wtMjQzNzY5OTctdm1zczAwMDAxNyoVCgZkZXZpY2USC3Zlbmtpc3N1ZTAyKiUKEm5ldHdvcmtzZXJ2aWNlbmFtZRIPdmVua2lzc3VldG9wbzAxMgdSVU5OSU5H]"
time="2020-05-29T07:41:50Z" level=info msg="Values: [NSE topoex01zgtmx nsm-16 Cg4KCHRvcG9leDAxEgJJUBI/CiFrOHMtYWdlbnRwb29sLTI0Mzc2OTk3LXZtc3MwMDAwMTcSETEwLjI0MC4wLjEyOTo1MDAxIgdSVU5OSU5HGn4KDXRvcG9leDAxemd0bXgSAklQGgh0b3BvZXgwMSIhazhzLWFnZW50cG9vbC0yNDM3Njk5Ny12bXNzMDAwMDE3KhMKBmRldmljZRIJZXhhbXBsZTAyKh4KEm5ldHdvcmtzZXJ2aWNlbmFtZRIIdG9wb2V4MDEyB1JVTk5JTkc=]"
time="2020-05-29T07:41:50Z" level=info msg="Clients: [nsm-17 nsm-27 nsm-13 nsm-16 nsm-15]"
time="2020-05-29T07:41:50Z" level=info msg="NSEs: map[topoex01zgtmx:{nsm-16 network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" > } venkissuetopo016vddh:{nsm-15 network_service:<name:"venkissuetopo01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"venkissuetopo016vddh" payload:"IP" network_service_name:"venkissuetopo01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"venkissue02" > labels:<key:"networkservicename" value:"venkissuetopo01" > state:"RUNNING" > }]"
time="2020-05-29T07:41:50Z" level=info msg=">><<------ clients=["nsm-17","nsm-27","nsm-13","nsm-16","nsm-15"] span={}"
time="2020-05-29T07:41:50Z" level=info msg=">><<------ endpoints={"topoex01zgtmx":{"Workspace":"nsm-16","NseReg":{"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}}},"venkissuetopo016vddh":{"Workspace":"nsm-15","NseReg":{"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"venkissuetopo016vddh","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"}}}} span={}"
time="2020-05-29T07:41:50Z" level=info msg="==--------> restoreClients() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="NSMServer: Creating workspaces for existing clients..." operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==----------> Workspace:nsm-17() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new workspace: nsm-17" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- restore=true span={}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new directory: /var/lib/networkservicemesh/nsm-17" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new listener on: /var/lib/networkservicemesh/nsm-17/nsm.server.io.sock" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceRegistryServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new MonitorConnectionServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="Creating new GRPC MonitorServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> NewServer() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceRegistryServer with registerServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="LocalConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceDiscoveryServer with discoveryServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceServer with registerServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering MonitorConnectionServer with registerServer" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="grpcserver for workspace &{name:nsm-17 listener:0xc00029f980 registryServer:0xc00029fa20 networkServiceServer:0xc0003d88a0 monitorConnectionServer:0xc00029fac0 grpcServer:0xc0002a5500 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0003d8210 discoveryServer:0xc000297d80} is operational" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Created new workspace: &{name:nsm-17 listener:0xc00029f980 registryServer:0xc00029fa20 networkServiceServer:0xc0003d88a0 monitorConnectionServer:0xc00029fac0 grpcServer:0xc0002a5500 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0003d8210 discoveryServer:0xc000297d80}" operation="Workspace:nsm-17" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> cleanup() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Workspace for client nsm-17 created" operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==----------> Workspace:nsm-27() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new workspace: nsm-27" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- restore=true span={}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new directory: /var/lib/networkservicemesh/nsm-27" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new listener on: /var/lib/networkservicemesh/nsm-27/nsm.server.io.sock" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceRegistryServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new MonitorConnectionServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="LocalConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="Creating new GRPC MonitorServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> NewServer() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceRegistryServer with registerServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceDiscoveryServer with discoveryServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceServer with registerServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering MonitorConnectionServer with registerServer" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="grpcserver for workspace &{name:nsm-27 listener:0xc000408380 registryServer:0xc000408420 networkServiceServer:0xc0003d9470 monitorConnectionServer:0xc0004084c0 grpcServer:0xc0002a5c80 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0003d8e10 discoveryServer:0xc0003e9000} is operational" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Created new workspace: &{name:nsm-27 listener:0xc000408380 registryServer:0xc000408420 networkServiceServer:0xc0003d9470 monitorConnectionServer:0xc0004084c0 grpcServer:0xc0002a5c80 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0003d8e10 discoveryServer:0xc0003e9000}" operation="Workspace:nsm-27" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> cleanup() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Workspace for client nsm-27 created" operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==----------> Workspace:nsm-13() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new workspace: nsm-13" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- restore=true span={}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new directory: /var/lib/networkservicemesh/nsm-13" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new listener on: /var/lib/networkservicemesh/nsm-13/nsm.server.io.sock" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceRegistryServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new MonitorConnectionServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="Creating new GRPC MonitorServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> NewServer() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceRegistryServer with registerServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceDiscoveryServer with discoveryServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceServer with registerServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering MonitorConnectionServer with registerServer" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="LocalConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="grpcserver for workspace &{name:nsm-13 listener:0xc000409100 registryServer:0xc0004091a0 networkServiceServer:0xc0004c2690 monitorConnectionServer:0xc000409240 grpcServer:0xc000460c00 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0004c2030 discoveryServer:0xc0004c0630} is operational" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Created new workspace: &{name:nsm-13 listener:0xc000409100 registryServer:0xc0004091a0 networkServiceServer:0xc0004c2690 monitorConnectionServer:0xc000409240 grpcServer:0xc000460c00 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc0004c2030 discoveryServer:0xc0004c0630}" operation="Workspace:nsm-13" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> cleanup() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Workspace for client nsm-13 created" operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==----------> Workspace:nsm-16() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new workspace: nsm-16" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- restore=true span={}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new directory: /var/lib/networkservicemesh/nsm-16" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new listener on: /var/lib/networkservicemesh/nsm-16/nsm.server.io.sock" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceRegistryServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new MonitorConnectionServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="LocalConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="Creating new GRPC MonitorServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> NewServer() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceRegistryServer with registerServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceDiscoveryServer with discoveryServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceServer with registerServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering MonitorConnectionServer with registerServer" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="grpcserver for workspace &{name:nsm-16 listener:0xc00000c9e0 registryServer:0xc00000ca80 networkServiceServer:0xc0001775f0 monitorConnectionServer:0xc00000cb20 grpcServer:0xc00023a300 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc000176f90 discoveryServer:0xc000030da0} is operational" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Created new workspace: &{name:nsm-16 listener:0xc00000c9e0 registryServer:0xc00000ca80 networkServiceServer:0xc0001775f0 monitorConnectionServer:0xc00000cb20 grpcServer:0xc00023a300 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc000176f90 discoveryServer:0xc000030da0}" operation="Workspace:nsm-16" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> cleanup() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Workspace for client nsm-16 created" operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==----------> Workspace:nsm-15() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new workspace: nsm-15" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- restore=true span={}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new directory: /var/lib/networkservicemesh/nsm-15" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new listener on: /var/lib/networkservicemesh/nsm-15/nsm.server.io.sock" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceRegistryServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new MonitorConnectionServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Creating new NetworkServiceServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="LocalConnection - Serve starting..."
time="2020-05-29T07:41:50Z" level=info msg="Reading excluded prefixes config file: /var/lib/networkservicemesh/config/excluded_prefixes.yaml"
time="2020-05-29T07:41:50Z" level=info msg="Excluded prefixes: []"
time="2020-05-29T07:41:50Z" level=info msg="Creating new GRPC MonitorServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> NewServer() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceRegistryServer with registerServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceDiscoveryServer with discoveryServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering NetworkServiceServer with registerServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Registering MonitorConnectionServer with registerServer" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="grpcserver for workspace &{name:nsm-15 listener:0xc00000d760 registryServer:0xc00000d800 networkServiceServer:0xc0002ef020 monitorConnectionServer:0xc00000d8a0 grpcServer:0xc0003fd680 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc00056a1b0 discoveryServer:0xc0005bc3d0} is operational" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="Created new workspace: &{name:nsm-15 listener:0xc00000d760 registryServer:0xc00000d800 networkServiceServer:0xc0002ef020 monitorConnectionServer:0xc00000d8a0 grpcServer:0xc0003fd680 Mutex:{state:0 sema:0} state:2 locationProvider:0xc000154420 localRegistry:0xc00014c360 ctx:0xc00056a1b0 discoveryServer:0xc0005bc3d0}" operation="Workspace:nsm-15" span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==------------> cleanup() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Workspace for client nsm-15 created" operation=restoreClients span="{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<------ updated-clients=["nsm-17","nsm-27","nsm-13","nsm-16","nsm-15"] span={}"
time="2020-05-29T07:41:50Z" level=info msg="==--------> restore-endpoints() span:{}"
time="2020-05-29T07:41:50Z" level=info msg="Requesting NetworkServiceDiscoveryClient..."
time="2020-05-29T07:41:50Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:50Z" level=info msg="==----------> check-nse-venkissuetopo016vddh() span:{}"
time="2020-05-29T07:41:50Z" level=info msg=">><<---------- workspace={} span={}"
time="2020-05-29T07:41:50Z" level=info msg="Checking NSE venkissuetopo016vddh is alive at /var/lib/networkservicemesh/nsm-15/nsm.client.io.sock..." operation=check-nse-venkissuetopo016vddh span="{}"
time="2020-05-29T07:41:50Z" level=info msg="==--> check-nse-alive() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- GRPC->/registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- request={"network_service":{"name":"topoex01","payload":"IP"},"network_service_endpoint":{"payload":"IP","network_service_name":"topoex01","labels":{"device":"example01"}}} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==--> RegisterNSE() span:{}"
time="2020-05-29T07:41:51Z" level=info msg="Received RegisterNSE request: network_service:<name:"topoex01" payload:"IP" > network_service_endpoint:<payload:"IP" network_service_name:"topoex01" labels:<key:"device" value:"example01" > > " operation=RegisterNSE span="{}"
time="2020-05-29T07:41:51Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:51Z" level=info msg=">><<---- /registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---- request={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"url":"<IP_ADDRESS>:5001"},"network_service_endpoint":{"payload":"IP","network_service_name":"topoex01","labels":{"device":"example01"}}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---- response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01s9m6r","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example01","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01s9m6r" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example01" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-27/nsm.client.io.sock nsm-27}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01s9m6r" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example01" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-27/nsm.client.io.sock nsm-27}"
time="2020-05-29T07:41:51Z" level=info msg="Received upstream NSERegitration: network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01s9m6r" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example01" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" > "
time="2020-05-29T07:41:51Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:51Z" level=info msg=">><<-- registration={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01s9m6r","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example01","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01s9m6r","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example01","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- GRPC->/registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- request={"network_service":{"name":"topoex01","payload":"IP"},"network_service_endpoint":{"payload":"IP","network_service_name":"topoex01","labels":{"device":"example02"}}} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==--> RegisterNSE() span:{}"
time="2020-05-29T07:41:51Z" level=info msg="Received RegisterNSE request: network_service:<name:"topoex01" payload:"IP" > network_service_endpoint:<payload:"IP" network_service_name:"topoex01" labels:<key:"device" value:"example02" > > " operation=RegisterNSE span="{}"
time="2020-05-29T07:41:51Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:51Z" level=info msg=">><<---- /registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---- request={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"url":"<IP_ADDRESS>:5001"},"network_service_endpoint":{"payload":"IP","network_service_name":"topoex01","labels":{"device":"example02"}}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---- response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01gj5k4","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01gj5k4" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01gj5k4" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:51Z" level=info msg="Received upstream NSERegitration: network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01gj5k4" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" > "
time="2020-05-29T07:41:51Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:51Z" level=info msg=">><<-- registration={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01gj5k4","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01gj5k4","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- GRPC->/networkservice.NetworkService/Request()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==--> Local.*requestValidator.Request() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==----> Local.*monitorService.Request() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==------> Local.*workspaceProviderService.Request() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<------ request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topoex01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-171" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth1" > labels:<key:"podName" value:"example01-765dc4b68f-pmhv7" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth1" > parameters:<key:"netnsInode" value:"4026532486" > parameters:<key:"socketfile" value:"eth1/memif.sock" > > "
time="2020-05-29T07:41:51Z" level=info msg="==--------> Local.*connectionService.Request() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-------- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topoex01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-171" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth1" > labels:<key:"podName" value:"example01-765dc4b68f-pmhv7" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth1" > parameters:<key:"netnsInode" value:"4026532486" > parameters:<key:"socketfile" value:"eth1/memif.sock" > parameters:<key:"workspace" value:"nsm-13" > > " span="{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---------- connection-id= span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---------- workspace=nsm-13 span={}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded started: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:51Z" level=info msg="resourceAdded finished: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:51Z" level=info msg="==----------> Local.*forwarderService.Request() span:{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---------- request={"connection":{"id":"1","network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:51Z" level=info msg="==------------> wait-forwarder() span:{}"
time="2020-05-29T07:41:51Z" level=info msg="Waiting for forwarder available..." operation=wait-forwarder span="{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<-- alive=false span={}"
time="2020-05-29T07:41:51Z" level=error msg="unable to connect to local nse network_service:<name:"venkissuetopo01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"venkissuetopo016vddh" payload:"IP" network_service_name:"venkissuetopo01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"venkissue02" > labels:<key:"networkservicename" value:"venkissuetopo01" > state:"RUNNING" > . Skipping" operation=restore-endpoints span="{}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---------- /registry.NetworkServiceRegistry/RemoveNSE()="" span={}"
time="2020-05-29T07:41:51Z" level=info msg=">><<---------- request={"network_service_endpoint_name":"venkissuetopo016vddh"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==----------> check-nse-topoex01zgtmx() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- workspace={} span={}"
time="2020-05-29T07:41:52Z" level=info msg="Checking NSE topoex01zgtmx is alive at /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock..." operation=check-nse-topoex01zgtmx span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==--> check-nse-alive() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- alive=true span={}"
time="2020-05-29T07:41:52Z" level=info msg="NSE topoex01zgtmx is alive at /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock..." operation=restore-endpoints span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==----------> restoreEndpoint() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ /registry.NetworkServiceDiscovery/FindNetworkService()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ request={"network_service_name":"topoex01"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ /registry.NetworkServiceRegistry/RemoveNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ request={"network_service_endpoint_name":"topoex01zgtmx"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==------------> restoreNotRegisteredEndpoint-topoex01zgtmx() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ name="topoex01zgtmx" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-------------- /registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-------------- request={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"url":"<IP_ADDRESS>:5001"},"network_service_endpoint":{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-------------- response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="Received upstream NSERegitration: network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" > "
time="2020-05-29T07:41:52Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ reg-response={"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- /registry.NetworkServiceRegistry/RemoveNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- request={"network_service_endpoint_name":"venkissuetopo016vddh"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- response={} span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<-------- error=rpc error: code = Unknown desc = networkserviceendpoints.networkservicemesh.io "venkissuetopo016vddh" not found\nremove NSE: NSE %v\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/nsmd.(*nsmServer).restoreEndpoints\n\t/home/circleci/project/controlplane/pkg/nsmd/nsmd.go:319\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/nsmd.(*nsmServer).restore\n\t/home/circleci/project/controlplane/pkg/nsmd/nsmd.go:219\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/nsmd.StartNSMServer\n\t/home/circleci/project/controlplane/pkg/nsmd/nsmd.go:494\nmain.main\n\t/home/circleci/project/controlplane/cmd/nsmd/main.go:63\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:203\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- /registry.NetworkServiceRegistry/RemoveNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- request={"network_service_endpoint_name":"venkissuetopo01bg4fx"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- /registry.NetworkServiceRegistry/RemoveNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- request={"network_service_endpoint_name":"topoex01wzz6f"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------ updated-endpoints={"topoex01zgtmx":{"Workspace":"nsm-16","NseReg":{"network_service":{"name":"topoex01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"topoex01zgtmx","payload":"IP","network_service_name":"topoex01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"example02","networkservicename":"topoex01"},"state":"RUNNING"}}}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="save local client/nse registry" operation=restore span="{}"
time="2020-05-29T07:41:52Z" level=info msg="NSMD: Restore of NSE/Clients Complete..." operation=restore span="{}"
time="2020-05-29T07:41:52Z" level=info msg="NSM server is ready"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01s9m6r" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example01" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-27/nsm.client.io.sock nsm-27}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01s9m6r" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example01" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-27/nsm.client.io.sock nsm-27}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01gj5k4" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01gj5k4" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{network_service:<name:"topoex01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"topoex01zgtmx" payload:"IP" network_service_name:"topoex01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"example02" > labels:<key:"networkservicename" value:"topoex01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock nsm-16}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:52Z" level=info msg="Starting Forwarder registration server..."
time="2020-05-29T07:41:52Z" level=info msg="==----> ForwarderRegistrarServer() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="==------> NewServer() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==------> StartForwarderRegistrarServer() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------ path=/var/lib/networkservicemesh/nsm.forwarder-registrar.io.sock span={}"
time="2020-05-29T07:41:52Z" level=info msg="Starting Forwarder Registrar gRPC server listening on socket: /var/lib/networkservicemesh/nsm.forwarder-registrar.io.sock" operation=StartForwarderRegistrarServer span="{}"
time="2020-05-29T07:41:52Z" level=info msg="forwarder registrar Server socket: /var/lib/networkservicemesh/nsm.forwarder-registrar.io.sock is operational" operation=StartForwarderRegistrarServer span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==----> wait-forwarder() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="Waiting for forwarder available..." operation=wait-forwarder span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==--> EndpointAdded() span:"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Added"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Connecting to: /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock"
time="2020-05-29T07:41:52Z" level=info msg="==--> ClientConnectionAdded() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- clientConnection={"ConnectionID":"1","Request":null,"Xcon":null,"RemoteNsm":null,"Endpoint":null,"ForwarderRegisteredName":"","ConnectionState":1,"ForwarderState":0,"Span":null,"Monitor":{"Server":{}}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==--> EndpointAdded() span:"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Added"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Connecting to: /var/lib/networkservicemesh/nsm-27/nsm.client.io.sock"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Connected"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Started monitor"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Connected"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Started monitor"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Received event: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01zgtmx): Handler is nil, event: %v not handled: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="==--> EndpointAdded() span:"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Added"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Connecting to: /var/lib/networkservicemesh/nsm-16/nsm.client.io.sock"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Received event: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01s9m6r): Handler is nil, event: %v not handled: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Connected"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Started monitor"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Received event: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(topoex01gj5k4): Handler is nil, event: %v not handled: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- GRPC->/registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- request={"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_endpoint":{"payload":"IP","network_service_name":"venkissuetopo01","labels":{"device":"venkissue02"}}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==--> RegisterNSE() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="Received RegisterNSE request: network_service:<name:"venkissuetopo01" payload:"IP" > network_service_endpoint:<payload:"IP" network_service_name:"venkissuetopo01" labels:<key:"device" value:"venkissue02" > > " operation=RegisterNSE span="{}"
time="2020-05-29T07:41:52Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:52Z" level=info msg=">><<---- /registry.NetworkServiceRegistry/RegisterNSE()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---- request={"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_manager":{"url":"<IP_ADDRESS>:5001"},"network_service_endpoint":{"payload":"IP","network_service_name":"venkissuetopo01","labels":{"device":"venkissue02"}}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---- response={"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"venkissuetopo01bsp48","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{network_service:<name:"venkissuetopo01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"venkissuetopo01bsp48" payload:"IP" network_service_name:"venkissuetopo01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"venkissue02" > labels:<key:"networkservicename" value:"venkissuetopo01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-15/nsm.client.io.sock nsm-15}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{network_service:<name:"venkissuetopo01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"venkissuetopo01bsp48" payload:"IP" network_service_name:"venkissuetopo01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"venkissue02" > labels:<key:"networkservicename" value:"venkissuetopo01" > state:"RUNNING" >  /var/lib/networkservicemesh/nsm-15/nsm.client.io.sock nsm-15}"
time="2020-05-29T07:41:52Z" level=info msg="Received upstream NSERegitration: network_service:<name:"venkissuetopo01" payload:"IP" > network_service_manager:<name:"k8s-agentpool-24376997-vmss000017" url:"<IP_ADDRESS>:5001" state:"RUNNING" > network_service_endpoint:<name:"venkissuetopo01bsp48" payload:"IP" network_service_name:"venkissuetopo01" network_service_manager_name:"k8s-agentpool-24376997-vmss000017" labels:<key:"device" value:"venkissue02" > labels:<key:"networkservicename" value:"venkissuetopo01" > state:"RUNNING" > "
time="2020-05-29T07:41:52Z" level=info msg="Requesting NseRegistryClient..."
time="2020-05-29T07:41:52Z" level=info msg="==--> EndpointAdded() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Added"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Connecting to: /var/lib/networkservicemesh/nsm-15/nsm.client.io.sock"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Connected"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Started monitor"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Received event: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-EndpointMonitor(venkissuetopo01bsp48): Handler is nil, event: %v not handled: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000}}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- registration={"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"venkissuetopo01bsp48","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- response={"network_service":{"name":"venkissuetopo01","payload":"IP"},"network_service_manager":{"name":"k8s-agentpool-24376997-vmss000017","url":"<IP_ADDRESS>:5001","state":"RUNNING"},"network_service_endpoint":{"name":"venkissuetopo01bsp48","payload":"IP","network_service_name":"venkissuetopo01","network_service_manager_name":"k8s-agentpool-24376997-vmss000017","labels":{"device":"venkissue02","networkservicename":"venkissuetopo01"},"state":"RUNNING"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- GRPC->/forwarderregistrar.ForwarderRegistration/RequestForwarderRegistration()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- request={"forwarder_name":"kernel-forwarder","forwarder_socket":"/var/lib/networkservicemesh/nsm-vppagent.forwarder.sock"} span={}"
time="2020-05-29T07:41:52Z" level=info msg="Received new forwarder registration requests from kernel-forwarder"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded started: &{kernel-forwarder /var/lib/networkservicemesh/nsm-vppagent.forwarder.sock [] [] false}"
time="2020-05-29T07:41:52Z" level=info msg="resourceAdded finished: &{kernel-forwarder /var/lib/networkservicemesh/nsm-vppagent.forwarder.sock [] [] false}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- response={"registered":true} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==--> ForwarderAdded() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="==----> Forwarder-kernel-forwarder-monitor() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="Starting Forwarder crossconnect monitoring client..." operation=Forwarder-kernel-forwarder-monitor span="{}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-ForwarderMonitor(kernel-forwarder): Added"
time="2020-05-29T07:41:52Z" level=info msg="NSM-ForwarderMonitor(kernel-forwarder): Connecting to: /var/lib/networkservicemesh/nsm-vppagent.forwarder.sock"
time="2020-05-29T07:41:52Z" level=info msg="Liveness Request received"
time="2020-05-29T07:41:52Z" level=info msg="NSM-ForwarderMonitor(kernel-forwarder): Connected"
time="2020-05-29T07:41:52Z" level=info msg="NSM-ForwarderMonitor(kernel-forwarder): Started monitor"
time="2020-05-29T07:41:52Z" level=info msg="Forwarder kernel-forwarder informed of its parameters changes, applying new parameters [type:"VXLAN" parameters:<key:"src_ip" value:"<IP_ADDRESS>" >  type:"WIREGUARD" parameters:<key:"src_ip" value:"<IP_ADDRESS>" > ]"
time="2020-05-29T07:41:52Z" level=info msg="resourceUpdated started: &{kernel-forwarder /var/lib/networkservicemesh/nsm-vppagent.forwarder.sock [type:"KERNEL_INTERFACE" ] [type:"VXLAN" parameters:<key:"src_ip" value:"<IP_ADDRESS>" >  type:"WIREGUARD" parameters:<key:"src_ip" value:"<IP_ADDRESS>" > ] true}"
time="2020-05-29T07:41:52Z" level=info msg="resourceUpdated finished: &{kernel-forwarder /var/lib/networkservicemesh/nsm-vppagent.forwarder.sock [type:"KERNEL_INTERFACE" ] [type:"VXLAN" parameters:<key:"src_ip" value:"<IP_ADDRESS>" >  type:"WIREGUARD" parameters:<key:"src_ip" value:"<IP_ADDRESS>" > ] true}"
time="2020-05-29T07:41:52Z" level=info msg="NSM-ForwarderMonitor(kernel-forwarder): Received event: &{{INITIAL_STATE_TRANSFER map[] 0xc0000a4000} map[] }"
time="2020-05-29T07:41:52Z" level=info msg="==----> Nsmgr.RestoreConnections() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="All connections are recovered..." operation=Nsmgr.RestoreConnections span="{}"
time="2020-05-29T07:41:52Z" 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":"<IP_ADDRESS>"}},{"type":"WIREGUARD","parameters":{"src_ip":"<IP_ADDRESS>"}}],"MechanismsConfigured":true} span={}"
time="2020-05-29T07:41:52Z" level=info msg="==------------> Local.*endpointSelectorService.Request() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ request={"connection":{"id":"1","network_service":"topoex01","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-------------- requestNSEOnUpdate=false span={}"
time="2020-05-29T07:41:52Z" level=info msg="==--------------> select-nse-1() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="==----------------> GetEndpoint() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- request={"id":"1","network_service":"topoex01","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- ignores={} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- targetEndpoint="" span={}"
time="2020-05-29T07:41:52Z" level=info msg="Requesting NetworkServiceDiscoveryClient..."
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- nseRequest={"network_service_name":"topoex01"} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- /registry.NetworkServiceDiscovery/FindNetworkService()="" span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- request={"network_service_name":"topoex01"} span={}"
time="2020-05-29T07:41:52Z" level=info msg="Forwarder is available, waiting for initial state received and processed..."
time="2020-05-29T07:41:52Z" level=info msg="Forwarder server is ready" operation=nsmd.server span="{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- api-address=":5001" span={}"
time="2020-05-29T07:41:52Z" level=info msg="Public listener is ready" operation=nsmd.server span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==----> start-public-api-server() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="==------> NewServer() span:{}"
time="2020-05-29T07:41:52Z" level=info msg="GRPC.NewServer with open tracing enabled" operation=NewServer span="{}"
time="2020-05-29T07:41:52Z" level=info msg="NSM gRPC API Server: [::]:5001 is operational" operation=start-public-api-server span="{}"
time="2020-05-29T07:41:52Z" level=info msg="Serve api is ready" operation=nsmd.server span="{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- start-time=4.946549244s span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- response={} span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------------- nseResponse=null span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<---------------- error=rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<------------ error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------------ response=null span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<---------- error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- response=null span={}"
time="2020-05-29T07:41:52Z" level=info msg="resourceDeleted started: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:52Z" level=info msg="resourceDeleted finished: &{1      1 0  0xc000409240}"
time="2020-05-29T07:41:52Z" level=info msg="Do not close connection since healing" span="{}"
time="2020-05-29T07:41:52Z" level=info msg="==----------> ClientConnectionDeleted() span:{}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---------- clientConnection={"ConnectionID":"1","Request":null,"Xcon":null,"RemoteNsm":null,"Endpoint":null,"ForwarderRegisteredName":"","ConnectionState":1,"ForwarderState":0,"Span":null,"Monitor":{"Server":{}}} span={}"
time="2020-05-29T07:41:52Z" level=info msg="ClientConnectionDeleted: &{1      1 0  0xc000409240}" operation=ClientConnectionDeleted span="{}"
time="2020-05-29T07:41:52Z" level=info msg="Not a remote connection" operation=ClientConnectionDeleted span="{}"
time="2020-05-29T07:41:52Z" level=error msg=">><<-------- error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-------- response=null span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<------ error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<------ response=null span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<---- error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<---- response=null span={}"
time="2020-05-29T07:41:52Z" level=error msg=">><<-- error=NSM:(7.1.5) . Last NSE Error: rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).combineErrors\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:112\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*endpointSelectorService).Request\n\t/home/circleci/project/controlplane/pkg/local/endpoint_selector_service.go:78\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*forwarderService).Request\n\t/home/circleci/project/controlplane/pkg/local/forwarder_service.go:124\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*connectionService).Request\n\t/home/circleci/project/controlplane/pkg/local/connection_service.go:89\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/local.(*workspaceProviderService).Request\n\t/home/circleci/project/controlplane/pkg/local/workspace_service.go:46\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*monitorService).Request\n\t/home/circleci/project/controlplane/pkg/common/monitor_service.go:43\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*nextEndpoint).Request\n\t/home/circleci/project/controlplane/pkg/common/next.go:90\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.ProcessNext\n\t/home/circleci/project/controlplane/pkg/common/next.go:61\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*requestValidator).Request\n\t/home/circleci/project/controlplane/pkg/common/request_service.go:37\ngithub.com/networkservicemesh/networkservicemesh/controlplane/pkg/common.(*CompositeNetworkService).Request\n\t/home/circleci/project/controlplane/pkg/common/composite.go:45\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler.func1\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:179\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1.1\n\t/home/circleci/project/pkg/tools/interceptor.go:60\ngithub.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingServerInterceptor.func1\n\t/go/pkg/mod/github.com/grpc-ecosystem/grpc-opentracing@v0.0.0-20180507213350-8e809c8a8645/go/otgrpc/server.go:57\ngithub.com/networkservicemesh/networkservicemesh/pkg/tools.CloneArgsServerInterceptor.func1\n\t/home/circleci/project/pkg/tools/interceptor.go:64\ngithub.com/networkservicemesh/networkservicemesh/controlplane/api/networkservice._NetworkService_Request_Handler\n\t/home/circleci/project/controlplane/api/networkservice/networkservice.pb.go:181\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1024\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:1313\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.27.1/server.go:722\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1357 span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- response=null span={}"
time="2020-05-29T07:41:52Z" level=info msg=">><<-- response=null span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<-- GRPC->/networkservice.NetworkService/Request()="" span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<-- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="==--> Local.*requestValidator.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<-- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="==----> Local.*monitorService.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="==------> Local.*workspaceProviderService.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<------ request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topoex01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-171" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth1" > labels:<key:"podName" value:"example01-765dc4b68f-pmhv7" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth1" > parameters:<key:"netnsInode" value:"4026532486" > parameters:<key:"socketfile" value:"eth1/memif.sock" > > "
time="2020-05-29T07:41:57Z" level=info msg="==--------> Local.*connectionService.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<-------- request={"connection":{"network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="Received request from client to connect to NetworkService: connection:<network_service:"topoex01" context:<ip_context:<src_ip_required:true dst_ip_required:true > > labels:<key:"link" value:"net-171" > labels:<key:"namespace" value:"default" > labels:<key:"peerif" value:"eth1" > labels:<key:"podName" value:"example01-765dc4b68f-pmhv7" > > mechanism_preferences:<cls:"LOCAL" type:"KERNEL_INTERFACE" parameters:<key:"description" value:"Primary interface" > parameters:<key:"name" value:"eth1" > parameters:<key:"netnsInode" value:"4026532486" > parameters:<key:"socketfile" value:"eth1/memif.sock" > parameters:<key:"workspace" value:"nsm-13" > > " span="{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------- connection-id= span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------- workspace=nsm-13 span={}"
time="2020-05-29T07:41:57Z" level=info msg="resourceAdded started: &{2      1 0  0xc000409240}"
time="2020-05-29T07:41:57Z" level=info msg="resourceAdded finished: &{2      1 0  0xc000409240}"
time="2020-05-29T07:41:57Z" level=info msg="==----------> Local.*forwarderService.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------- request={"connection":{"id":"2","network_service":"topoex01","context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg="==------------> wait-forwarder() span:{}"
time="2020-05-29T07:41:57Z" level=info msg="Waiting for forwarder available..." operation=wait-forwarder span="{}"
time="2020-05-29T07:41:57Z" 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":"<IP_ADDRESS>"}},{"type":"WIREGUARD","parameters":{"src_ip":"<IP_ADDRESS>"}}],"MechanismsConfigured":true} span={}"
time="2020-05-29T07:41:57Z" level=info msg="==----------> ClientConnectionAdded() span:{}"
time="2020-05-29T07:41:57Z" level=info msg="==------------> Local.*endpointSelectorService.Request() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<------------ request={"connection":{"id":"2","network_service":"topoex01","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}},"mechanism_preferences":[{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}}]} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<-------------- requestNSEOnUpdate=false span={}"
time="2020-05-29T07:41:57Z" level=info msg="==--------------> select-nse-1() span:{}"
time="2020-05-29T07:41:57Z" level=info msg="==----------------> GetEndpoint() span:{}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- request={"id":"2","network_service":"topoex01","mechanism":{"cls":"LOCAL","type":"KERNEL_INTERFACE","parameters":{"description":"Primary interface","name":"eth1","netnsInode":"4026532486","socketfile":"eth1/memif.sock","workspace":"nsm-13"}},"context":{"ip_context":{"src_ip_required":true,"dst_ip_required":true}},"labels":{"link":"net-171","namespace":"default","peerif":"eth1","podName":"example01-765dc4b68f-pmhv7"}} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- ignores={} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- targetEndpoint="" span={}"
time="2020-05-29T07:41:57Z" level=info msg="Requesting NetworkServiceDiscoveryClient..."
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- nseRequest={"network_service_name":"topoex01"} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- /registry.NetworkServiceDiscovery/FindNetworkService()="" span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- request={"network_service_name":"topoex01"} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------- clientConnection={"ConnectionID":"2","Request":null,"Xcon":null,"RemoteNsm":null,"Endpoint":null,"ForwarderRegisteredName":"","ConnectionState":1,"ForwarderState":0,"Span":null,"Monitor":{"Server":{}}} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- response={} span={}"
time="2020-05-29T07:41:57Z" level=info msg=">><<---------------- nseResponse=null span={}"
time="2020-05-29T07:41:57Z" level=error msg=">><<---------------- error=rpc error: code = Unknown desc = networkservicemanagers.networkservicemesh.io "k8s-agentpool-24376997-vmss000015" not found span={}"