Skip to content

Instantly share code, notes, and snippets.

@stepan-anokhin

stepan-anokhin/all-logs--debug-enabled

Last active March 27, 2019 10:32
Show Gist options
  • Save stepan-anokhin/de085ce503e012a43be5e9d7794d9d20 to your computer and use it in GitHub Desktop.
Save stepan-anokhin/de085ce503e012a43be5e9d7794d9d20 to your computer and use it in GitHub Desktop.
Download ZIP
Bug in ligato/vpp-agent x-connect update
Raw
all-logs--debug-enabled
2019-03-27 09:55:51,523 DEBG 'vppagent-dataplane' stdout output:
time="2019-03-27T09:55:51Z" level=debug msg="Data change:
Interfaces:
name: "SRC-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bidkh9v8360"
Interfaces:
name: "DST-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bidkh9v836g"
XCons:
receive_interface: "SRC-some-id"
transmit_interface: "DST-some-id"
XCons:
receive_interface: "DST-some-id"
transmit_interface: "SRC-some-id"
LinuxInterfaces:
name: "SRC-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.1.1/30"
host_if_name: "if1_src"
namespace:
type: FILE_REF_NS
filepath: "/proc/12957/ns/net"
tap:
temp_if_name: "bidkh9v8360"
LinuxInterfaces:
name: "DST-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.1.2/30"
host_if_name: "if1_dst"
namespace:
type: FILE_REF_NS
filepath: "/proc/13188/ns/net"
tap:
temp_if_name: "bidkh9v836g"
2019-03-27 09:55:51,525 DEBG 'agent' stdout output:
time="2019-03-27 09:55:51.52503" level=debug msg="Processing change for key: "linux/config/v1/interface/SRC-some-id"" loc="linux/data_change.go(29)" logger=linux revision=0
time="2019-03-27 09:55:51.52570" level=debug msg="dataChangeIface false Put name:"SRC-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.1/30" host_if_name:"if1_src" namespace:<type:FILE_REF_NS filepath:"/proc/12957/ns/net" > tap:<temp_if_name:"bidkh9v8360" > " loc="linux/data_change.go(74)" logger=linux
time="2019-03-27 09:55:51.52593" level=debug msg="linux interface config SRC-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:51.52611" level=debug msg="creating new Linux Tap interface bidkh9v8360 configuration entry" loc="ifplugin/interface_config.go(349)" logger=linux.if-conf
time="2019-03-27 09:55:51.52645" level=debug msg="linux tap interface bidkh9v8360 is registered but not ready yet, configuration postponed" loc="ifplugin/interface_config.go(375)" logger=linux.if-conf
time="2019-03-27 09:55:51.52659" level=info msg="Linux interface SRC-some-id with hostIfName if1_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:51.52670" level=debug msg="Processing change for key: "linux/config/v1/interface/DST-some-id"" loc="linux/data_change.go(29)" logger=linux revision=0
time="2019-03-27 09:55:51.52687" level=debug msg="dataChangeIface false Put name:"DST-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.2/30" host_if_name:"if1_dst" namespace:<type:FILE_REF_NS filepath:"/proc/13188/ns/net" > tap:<temp_if_name:"bidkh9v836g" > " loc="linux/data_change.go(74)" logger=linux
time="2019-03-27 09:55:51.52700" level=debug msg="linux interface config DST-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:51.52712" level=debug msg="creating new Linux Tap interface bidkh9v836g configuration entry" loc="ifplugin/interface_config.go(349)" logger=linux.if-conf
time="2019-03-27 09:55:51.52732" level=debug msg="linux tap interface bidkh9v836g is registered but not ready yet, configuration postponed" loc="ifplugin/interface_config.go(375)" logger=linux.if-conf
time="2019-03-27 09:55:51.52742" level=info msg="Linux interface DST-some-id with hostIfName if1_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:51.52755" level=debug msg="Processing change for key: "vpp/config/v1/interface/SRC-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=0
time="2019-03-27 09:55:51.52775" level=debug msg="dataChangeIface false Put name:"SRC-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v8360" > " loc="vpp/data_change.go(416)" logger=vpp
time="2019-03-27 09:55:51.54645" level=debug msg="linux interface config SRC-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:51.54669" level=debug msg="linux tap interface bidkh9v8360 exists, can be configured" loc="ifplugin/interface_config.go(340)" logger=linux.if-conf
time="2019-03-27 09:55:51.54682" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-27 09:55:51.54709" level=debug msg="cached linux tap interface SRC-some-id unregistered" loc="ifplugin/interface_config.go(391)" logger=linux.if-conf
time="2019-03-27 09:55:51.55157" level=debug msg="publish add to linux{{SRC-some-id false false sw_if_indexes} 0xc000478400}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.55194" level=debug msg="publish add to ifplugin_ifstate{{SRC-some-id false false sw_if_indexes} 0xc000478400}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.55242" level=debug msg="publish add to vpp{{SRC-some-id false false sw_if_indexes} 0xc000478400}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.55265" level=debug msg="Interface SRC-some-id registered to interface mapping" loc="ifplugin/interface_config.go(299)" logger=vpp.if-conf
time="2019-03-27 09:55:51.55632" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-27 09:55:51.56099" level=info msg="Interface SRC-some-id configured" loc="ifplugin/interface_config.go(320)" logger=vpp.if-conf
time="2019-03-27 09:55:51.56122" level=debug msg="Processing change for key: "vpp/config/v1/interface/DST-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=0
time="2019-03-27 09:55:51.56148" level=debug msg="dataChangeIface false Put name:"DST-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v836g" > " loc="vpp/data_change.go(416)" logger=vpp
time="2019-03-27 09:55:51.59037" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-27 09:55:51.59865" level=debug msg="publish add to linux{{DST-some-id false false sw_if_indexes} 0xc000479100}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.59891" level=debug msg="publish add to ifplugin_ifstate{{DST-some-id false false sw_if_indexes} 0xc000479100}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.59915" level=debug msg="publish add to vpp{{DST-some-id false false sw_if_indexes} 0xc000479100}" loc="mem/inmemory_name_mapping.go(254)" logger=vpp.if-conf
time="2019-03-27 09:55:51.59937" level=debug msg="Interface DST-some-id registered to interface mapping" loc="ifplugin/interface_config.go(299)" logger=vpp.if-conf
time="2019-03-27 09:55:51.60189" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-27 09:55:51.60547" level=info msg="Interface DST-some-id configured" loc="ifplugin/interface_config.go(320)" logger=vpp.if-conf
time="2019-03-27 09:55:51.60576" level=info msg="there is no linux tap configuration entry for interface bidkh9v8360" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-27 09:55:51.60597" level=debug msg="Processing change for key: "vpp/config/v1/xconnect/SRC-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=0
time="2019-03-27 09:55:51.60684" level=debug msg="dataChangeXCon false Put receive_interface:"SRC-some-id" transmit_interface:"DST-some-id" " loc="vpp/data_change.go(509)" logger=vpp
time="2019-03-27 09:55:51.60903" level=debug msg="XConnect %!s(uint32=2)-%!s(uint32=3) removed from (del) cache" loc="l2plugin/xconnect_config.go(120)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.60924" level=debug msg="XConnect %!s(uint32=2)-%!s(uint32=3) registered" loc="l2plugin/xconnect_config.go(124)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.60941" level=info msg="L2 XConnect pair SRC-some-id-DST-some-id configured" loc="l2plugin/xconnect_config.go(126)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.60983" level=debug msg="Processing change for key: "vpp/config/v1/xconnect/DST-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=0
time="2019-03-27 09:55:51.61007" level=debug msg="dataChangeXCon false Put receive_interface:"DST-some-id" transmit_interface:"SRC-some-id" " loc="vpp/data_change.go(509)" logger=vpp
time="2019-03-27 09:55:51.61251" level=debug msg="XConnect %!s(uint32=3)-%!s(uint32=2) removed from (del) cache" loc="l2plugin/xconnect_config.go(120)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.61273" level=debug msg="XConnect %!s(uint32=3)-%!s(uint32=2) registered" loc="l2plugin/xconnect_config.go(124)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.61290" level=info msg="L2 XConnect pair DST-some-id-SRC-some-id configured" loc="l2plugin/xconnect_config.go(126)" logger=vpp.xc-conf
time="2019-03-27 09:55:51.61320" level=debug msg="linux interface config DST-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:51.61319" level=debug msg="TX Done - all events callbacks received" loc="syncbase/done.go(79)" logger=defaultLogger
time="2019-03-27 09:55:51.61341" level=debug msg="linux tap interface bidkh9v836g exists, can be configured" loc="ifplugin/interface_config.go(340)" logger=linux.if-conf
time="2019-03-27 09:55:51.61424" level=debug msg="cached linux tap interface DST-some-id unregistered" loc="ifplugin/interface_config.go(391)" logger=linux.if-conf
time="2019-03-27 09:55:51.61473" level=info msg="transport: loopyWriter.run returning. connection error: desc = "transport is closing"" loc="grpclog/logger.go(55)" logger=grpc.grpc-server
time="2019-03-27 09:55:51.61537" level=debug msg="publish add to linux{{SRC-some-id false false linux_if_indexes} 0xc000435680}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:51.61567" level=debug msg="publish add to vpp{{SRC-some-id false false linux_if_indexes} 0xc000435680}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:51.61590" level=debug msg="Linux interface SRC-some-id registered" loc="ifplugin/interface_config.go(494)" logger=linux.if-conf
time="2019-03-27 09:55:51.61614" level=info msg="Linux interface SRC-some-id with hostIfName if1_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:51.61629" level=debug msg="linux interface config DST-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:51.61643" level=debug msg="creating new Linux Tap interface bidkh9v836g configuration entry" loc="ifplugin/interface_config.go(349)" logger=linux.if-conf
time="2019-03-27 09:55:51.63024" level=debug msg="Memif socket dump completed, found 1 entries" loc="vppcalls/dump_interface_vppcalls.go(279)" logger=vpp.if-state
time="2019-03-27 09:55:51.63829" level=debug msg="linux tap interface bidkh9v836g is registered but not ready yet, configuration postponed" loc="ifplugin/interface_config.go(375)" logger=linux.if-conf
time="2019-03-27 09:55:51.63848" level=info msg="Linux interface DST-some-id with hostIfName if1_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:51.64650" level=warning msg="Received rx-placement data for unknown interface with index 3" loc="vppcalls/dump_interface_vppcalls.go(299)" logger=vpp.if-state
time="2019-03-27 09:55:51.64765" level=debug msg="Global interface state data added: internal_name:"tap0" index:2 status:"DOWN" mac_address:"02:fe:f2:8d:df:4e" " loc="statuscheck/plugin_impl_statuscheck.go(247)" logger=status-check
time="2019-03-27 09:55:51.65936" level=debug msg="publish add to vpp{{DST-some-id false false linux_if_indexes} 0xc0002b1c80}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:51.65980" level=debug msg="publish add to linux{{DST-some-id false false linux_if_indexes} 0xc0002b1c80}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:51.65999" level=debug msg="Linux interface DST-some-id registered" loc="ifplugin/interface_config.go(494)" logger=linux.if-conf
time="2019-03-27 09:55:51.66116" level=debug msg="Linux interface if1_src registered as host" loc="ifplugin/afpacket_config.go(171)" logger=vpp.if-conf
time="2019-03-27 09:55:51.66226" level=debug msg="Linux interface if1_dst registered as host" loc="ifplugin/afpacket_config.go(171)" logger=vpp.if-conf
time="2019-03-27 09:55:51.67784" level=debug msg="Memif socket dump completed, found 1 entries" loc="vppcalls/dump_interface_vppcalls.go(279)" logger=vpp.if-state
time="2019-03-27 09:55:51.68921" level=debug msg="Global interface state data added: internal_name:"tap1" index:3 status:"UP" mac_address:"02:fe:f4:32:55:3a" " loc="statuscheck/plugin_impl_statuscheck.go(247)" logger=status-check
2019-03-27 09:55:56,725 DEBG 'vppagent-dataplane' stdout output:
time="2019-03-27T09:55:56Z" level=debug msg="Data change:
Interfaces:
name: "SRC-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bidkh9v8360"
Interfaces:
name: "DST-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bidkh9v836g"
XCons:
receive_interface: "SRC-some-id"
transmit_interface: "DST-some-id"
XCons:
receive_interface: "DST-some-id"
transmit_interface: "SRC-some-id"
LinuxInterfaces:
name: "SRC-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.2.1/30"
host_if_name: "if2_src"
namespace:
type: FILE_REF_NS
filepath: "/proc/12957/ns/net"
tap:
temp_if_name: "bidkh9v8360"
LinuxInterfaces:
name: "DST-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.2.2/30"
host_if_name: "if2_dst"
namespace:
type: FILE_REF_NS
filepath: "/proc/13188/ns/net"
tap:
temp_if_name: "bidkh9v836g"
2019-03-27 09:55:56,726 DEBG 'agent' stdout output:
time="2019-03-27 09:55:56.72576" level=debug msg="Processing change for key: "linux/config/v1/interface/SRC-some-id"" loc="linux/data_change.go(29)" logger=linux revision=1
time="2019-03-27 09:55:56.72601" level=debug msg="dataChangeIface true Put name:"SRC-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.2.1/30" host_if_name:"if2_src" namespace:<type:FILE_REF_NS filepath:"/proc/12957/ns/net" > tap:<temp_if_name:"bidkh9v8360" > name:"SRC-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.1/30" host_if_name:"if1_src" namespace:<type:FILE_REF_NS filepath:"/proc/12957/ns/net" > tap:<temp_if_name:"bidkh9v8360" > " loc="linux/data_change.go(74)" logger=linux
time="2019-03-27 09:55:56.72617" level=debug msg="Linux interface with name SRC-some-id was removed from if-by-name cache" loc="ifplugin/interface_config.go(853)" logger=linux.if-conf
time="2019-03-27 09:55:56.77547" level=debug msg="publish del to linux{{SRC-some-id true false linux_if_indexes} 0xc000435680}" loc="mem/inmemory_name_mapping.go(300)" logger=linux
time="2019-03-27 09:55:56.77584" level=debug msg="publish del to vpp{{SRC-some-id true false linux_if_indexes} 0xc000435680}" loc="mem/inmemory_name_mapping.go(300)" logger=linux
time="2019-03-27 09:55:56.77616" level=debug msg="Interface name:"SRC-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.1/30" host_if_name:"if1_src" namespace:<type:FILE_REF_NS filepath:"/proc/12957/ns/net" > tap:<temp_if_name:"bidkh9v8360" > unregistered" loc="ifplugin/interface_config.go(719)" logger=linux.if-conf
time="2019-03-27 09:55:56.77636" level=info msg="Linux interface if1_src removed" loc="ifplugin/interface_config.go(282)" logger=linux.if-conf
time="2019-03-27 09:55:56.77654" level=debug msg="linux interface config SRC-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:56.77673" level=debug msg="creating new Linux Tap interface bidkh9v8360 configuration entry" loc="ifplugin/interface_config.go(349)" logger=linux.if-conf
time="2019-03-27 09:55:56.77709" level=debug msg="cached linux tap interface SRC-some-id unregistered" loc="ifplugin/interface_config.go(391)" logger=linux.if-conf
time="2019-03-27 09:55:56.81913" level=debug msg="publish add to linux{{SRC-some-id false false linux_if_indexes} 0xc000323e00}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:56.81943" level=debug msg="publish add to vpp{{SRC-some-id false false linux_if_indexes} 0xc000323e00}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:56.81968" level=debug msg="Linux interface SRC-some-id registered" loc="ifplugin/interface_config.go(494)" logger=linux.if-conf
time="2019-03-27 09:55:56.82001" level=info msg="Linux interface SRC-some-id with hostIfName if2_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:56.82026" level=debug msg="Processing change for key: "linux/config/v1/interface/DST-some-id"" loc="linux/data_change.go(29)" logger=linux revision=1
time="2019-03-27 09:55:56.82063" level=debug msg="dataChangeIface true Put name:"DST-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.2.2/30" host_if_name:"if2_dst" namespace:<type:FILE_REF_NS filepath:"/proc/13188/ns/net" > tap:<temp_if_name:"bidkh9v836g" > name:"DST-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.2/30" host_if_name:"if1_dst" namespace:<type:FILE_REF_NS filepath:"/proc/13188/ns/net" > tap:<temp_if_name:"bidkh9v836g" > " loc="linux/data_change.go(74)" logger=linux
time="2019-03-27 09:55:56.82088" level=debug msg="Linux interface with name DST-some-id was removed from if-by-name cache" loc="ifplugin/interface_config.go(853)" logger=linux.if-conf
time="2019-03-27 09:55:56.86350" level=debug msg="publish del to linux{{DST-some-id true false linux_if_indexes} 0xc0002b1c80}" loc="mem/inmemory_name_mapping.go(300)" logger=linux
time="2019-03-27 09:55:56.86379" level=debug msg="publish del to vpp{{DST-some-id true false linux_if_indexes} 0xc0002b1c80}" loc="mem/inmemory_name_mapping.go(300)" logger=linux
time="2019-03-27 09:55:56.86418" level=debug msg="Interface name:"DST-some-id" description:"Some description" type:AUTO_TAP enabled:true ip_addresses:"10.30.1.2/30" host_if_name:"if1_dst" namespace:<type:FILE_REF_NS filepath:"/proc/13188/ns/net" > tap:<temp_if_name:"bidkh9v836g" > unregistered" loc="ifplugin/interface_config.go(719)" logger=linux.if-conf
time="2019-03-27 09:55:56.86439" level=info msg="Linux interface if1_dst removed" loc="ifplugin/interface_config.go(282)" logger=linux.if-conf
time="2019-03-27 09:55:56.86460" level=debug msg="linux interface config DST-some-id cached to if-by-name" loc="ifplugin/interface_config.go(807)" logger=linux.if-conf
time="2019-03-27 09:55:56.86484" level=debug msg="linux tap interface bidkh9v836g exists, can be configured" loc="ifplugin/interface_config.go(340)" logger=linux.if-conf
time="2019-03-27 09:55:56.86522" level=debug msg="cached linux tap interface DST-some-id unregistered" loc="ifplugin/interface_config.go(391)" logger=linux.if-conf
time="2019-03-27 09:55:56.91539" level=debug msg="publish add to linux{{DST-some-id false false linux_if_indexes} 0xc0005757e0}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:56.91571" level=debug msg="publish add to vpp{{DST-some-id false false linux_if_indexes} 0xc0005757e0}" loc="mem/inmemory_name_mapping.go(254)" logger=linux
time="2019-03-27 09:55:56.91594" level=debug msg="Linux interface DST-some-id registered" loc="ifplugin/interface_config.go(494)" logger=linux.if-conf
time="2019-03-27 09:55:56.91632" level=info msg="Linux interface DST-some-id with hostIfName if2_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-27 09:55:56.91654" level=debug msg="Linux interface if1_src unregistered as host" loc="ifplugin/afpacket_config.go(196)" logger=vpp.if-conf
time="2019-03-27 09:55:56.91861" level=debug msg="Linux interface if2_src registered as host" loc="ifplugin/afpacket_config.go(171)" logger=vpp.if-conf
time="2019-03-27 09:55:56.91881" level=debug msg="Processing change for key: "vpp/config/v1/interface/DST-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=1
time="2019-03-27 09:55:56.91917" level=debug msg="dataChangeIface true Put name:"DST-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v836g" > name:"DST-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v836g" > " loc="vpp/data_change.go(416)" logger=vpp
time="2019-03-27 09:55:56.91955" level=debug msg="publish update to vpp{{DST-some-id false true sw_if_indexes} 0xc000575f00}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.91986" level=debug msg="publish update to linux{{DST-some-id false true sw_if_indexes} 0xc000575f00}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92017" level=debug msg="publish update to ifplugin_ifstate{{DST-some-id false true sw_if_indexes} 0xc000575f00}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92042" level=debug msg="Metadata updated in interface mapping for DST-some-id" loc="ifplugin/interface_config.go(628)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92064" level=info msg="Interface DST-some-id modified" loc="ifplugin/interface_config.go(468)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92082" level=debug msg="Linux interface if1_dst unregistered as host" loc="ifplugin/afpacket_config.go(196)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92099" level=debug msg="Processing change for key: "vpp/config/v1/interface/SRC-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=1
time="2019-03-27 09:55:56.92141" level=debug msg="dataChangeIface true Put name:"SRC-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v8360" > name:"SRC-some-id" type:TAP_INTERFACE enabled:true tap:<version:2 host_if_name:"bidkh9v8360" > " loc="vpp/data_change.go(416)" logger=vpp
time="2019-03-27 09:55:56.92185" level=debug msg="publish update to linux{{SRC-some-id false true sw_if_indexes} 0xc0004c62e0}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92209" level=debug msg="publish update to ifplugin_ifstate{{SRC-some-id false true sw_if_indexes} 0xc0004c62e0}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92229" level=debug msg="publish update to vpp{{SRC-some-id false true sw_if_indexes} 0xc0004c62e0}" loc="mem/inmemory_name_mapping.go(277)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92248" level=debug msg="Metadata updated in interface mapping for SRC-some-id" loc="ifplugin/interface_config.go(628)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92262" level=info msg="Interface SRC-some-id modified" loc="ifplugin/interface_config.go(468)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92275" level=debug msg="Processing change for key: "vpp/config/v1/xconnect/SRC-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=1
time="2019-03-27 09:55:56.92296" level=debug msg="dataChangeXCon true Put receive_interface:"SRC-some-id" transmit_interface:"DST-some-id" receive_interface:"SRC-some-id" transmit_interface:"DST-some-id" " loc="vpp/data_change.go(509)" logger=vpp
time="2019-03-27 09:55:56.92379" level=debug msg="Modifying XConnect: new entry SRC-some-id-DST-some-id added" loc="l2plugin/xconnect_config.go(171)" logger=vpp.xc-conf
time="2019-03-27 09:55:56.92397" level=info msg="L2 XConnect pair (rx: SRC-some-id) modified" loc="l2plugin/xconnect_config.go(173)" logger=vpp.xc-conf
time="2019-03-27 09:55:56.92412" level=info msg="there is no linux tap configuration entry for interface bidkh9v836g" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-27 09:55:56.92428" level=debug msg="Processing change for key: "vpp/config/v1/xconnect/DST-some-id"" loc="vpp/data_change.go(43)" logger=vpp revision=1
time="2019-03-27 09:55:56.92449" level=debug msg="dataChangeXCon true Put receive_interface:"DST-some-id" transmit_interface:"SRC-some-id" receive_interface:"DST-some-id" transmit_interface:"SRC-some-id" " loc="vpp/data_change.go(509)" logger=vpp
time="2019-03-27 09:55:56.92583" level=debug msg="Modifying XConnect: new entry DST-some-id-SRC-some-id added" loc="l2plugin/xconnect_config.go(171)" logger=vpp.xc-conf
time="2019-03-27 09:55:56.92599" level=info msg="L2 XConnect pair (rx: DST-some-id) modified" loc="l2plugin/xconnect_config.go(173)" logger=vpp.xc-conf
time="2019-03-27 09:55:56.92612" level=debug msg="Linux interface if1_dst registered as host" loc="ifplugin/afpacket_config.go(171)" logger=vpp.if-conf
time="2019-03-27 09:55:56.92617" level=debug msg="TX Done - all events callbacks received" loc="syncbase/done.go(79)" logger=defaultLogger
time="2019-03-27 09:55:56.92626" level=info msg="there is no linux tap configuration entry for interface bidkh9v8360" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-27 09:55:56.92802" level=info msg="transport: loopyWriter.run returning. connection error: desc = "transport is closing"" loc="grpclog/logger.go(55)" logger=grpc.grpc-server
time="2019-03-27T09:56:20Z" level=info msg="Executing: [vppctl sh int] in pod nsmd-dataplane-ci-21632-master:vppagent-dataplane"
time="2019-03-27T09:56:21Z" level=error msg="Output of 'vppctl sh int' on 'nsmd-dataplane-ci-21632-master':
Name Idx State MTU (L3/IP4/IP6/MPLS) Counter Count
host-eth0 1 up 9000/0/0/0 rx packets 6
rx bytes 356
drops 6
ip6 3
local0 0 down 0/0/0/0
tap0 2 up 9000/0/0/0 rx packets 6
rx bytes 364
tx packets 3
tx bytes 238
tap1 3 up 9000/0/0/0 rx packets 3
rx bytes 238
tx packets 6
tx bytes 364
time="2019-03-27T09:56:21Z" level=info msg="Executing: [ip addr] in pod nsmd-dataplane-ci-21632-master:vppagent-dataplane"
time="2019-03-27T09:56:22Z" level=error msg="Output of 'ip addr' on 'nsmd-dataplane-ci-21632-master':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
30: eth0@if31: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1376 qdisc noqueue state UP group default
link/ether 36:1e:ba:11:2c:b8 brd ff:ff:ff:ff:ff:ff link-netnsid 0
inet 192.168.0.4/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
time="2019-03-27T09:56:22Z" level=info msg="Executing: [ip addr] in pod source-pod:alpine-img"
time="2019-03-27T09:56:23Z" level=error msg="Output of 'ip addr' on 'source-pod':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
2: if2_src: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 5e:f5:ae:73:86:3f brd ff:ff:ff:ff:ff:ff
inet 10.30.2.1/30 brd 10.30.2.3 scope global if2_src
valid_lft forever preferred_lft forever
32: eth0@if33: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1376 qdisc noqueue state UP
link/ether 0a:94:d0:6c:53:c3 brd ff:ff:ff:ff:ff:ff
inet 192.168.0.5/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
time="2019-03-27T09:56:23Z" level=info msg="Executing: [ip addr] in pod destination-pod:alpine-img"
time="2019-03-27T09:56:23Z" level=error msg="Output of 'ip addr' on 'destination-pod':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
3: if1_dst: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether e6:94:82:dd:c1:08 brd ff:ff:ff:ff:ff:ff
inet 10.30.1.2/30 brd 10.30.1.3 scope global if1_dst
valid_lft forever preferred_lft forever
34: eth0@if35: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1376 qdisc noqueue state UP
link/ether c2:54:3b:42:b0:ee brd ff:ff:ff:ff:ff:ff
inet 192.168.0.6/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
Raw
ip-addr-dest-pod.txt
time="2019-03-26T12:21:53Z" level=info msg="Executing: [ip addr] in pod destination-pod:alpine-img"
time="2019-03-26T12:21:53Z" level=error msg="Output of 'ip addr' on 'destination-pod':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
3: if1_dst: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether fa:4e:83:70:b4:cf brd ff:ff:ff:ff:ff:ff
inet 10.30.1.2/30 brd 10.30.1.3 scope global if1_dst
valid_lft forever preferred_lft forever
34: eth0@if35: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1376 qdisc noqueue state UP
link/ether 7a:19:4d:c0:17:57 brd ff:ff:ff:ff:ff:ff
inet 192.168.0.6/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
Raw
ip-addr-source-pod.txt
time="2019-03-26T12:21:52Z" level=info msg="Executing: [ip addr] in pod source-pod:alpine-img"
time="2019-03-26T12:21:53Z" level=error msg="Output of 'ip addr' on 'source-pod':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
2: if2_src: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 3e:cb:d6:0f:be:ca brd ff:ff:ff:ff:ff:ff
inet 10.30.2.1/30 brd 10.30.2.3 scope global if2_src
valid_lft forever preferred_lft forever
32: eth0@if33: <BROADCAST,MULTICAST,UP,LOWER_UP,M-DOWN> mtu 1376 qdisc noqueue state UP
link/ether da:d5:6e:11:91:b3 brd ff:ff:ff:ff:ff:ff
inet 192.168.0.5/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
Raw
ip-addr-vpp.txt
time="2019-03-26T12:21:51Z" level=info msg="Executing: [ip addr] in pod nsmd-dataplane-ci-21361-master:vppagent-dataplane"
time="2019-03-26T12:21:52Z" level=error msg="Output of 'ip addr' on 'nsmd-dataplane-ci-21361-master':
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1
link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
inet 127.0.0.1/8 scope host lo
valid_lft forever preferred_lft forever
30: eth0@if31: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1376 qdisc noqueue state UP group default
link/ether 86:69:85:f7:6d:82 brd ff:ff:ff:ff:ff:ff link-netnsid 0
inet 192.168.0.4/16 brd 192.168.255.255 scope global eth0
valid_lft forever preferred_lft forever
Raw
request-first.txt
Interfaces:
name: "SRC-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bid1ifss11g"
Interfaces:
name: "DST-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bid1ifss120"
XCons:
receive_interface: "SRC-some-id"
transmit_interface: "DST-some-id"
XCons:
receive_interface: "DST-some-id"
transmit_interface: "SRC-some-id"
LinuxInterfaces:
name: "SRC-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.1.1/30"
host_if_name: "if1_src"
namespace:
type: FILE_REF_NS
filepath: "/proc/13189/ns/net"
tap:
temp_if_name: "bid1ifss11g"
LinuxInterfaces:
name: "DST-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.1.2/30"
host_if_name: "if1_dst"
namespace:
type: FILE_REF_NS
filepath: "/proc/13418/ns/net"
tap:
temp_if_name: "bid1ifss120"
Raw
request-second.txt
Interfaces:
name: "SRC-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bid1ifss11g"
Interfaces:
name: "DST-some-id"
type: TAP_INTERFACE
enabled: true
tap:
version: 2
host_if_name: "bid1ifss120"
XCons:
receive_interface: "SRC-some-id"
transmit_interface: "DST-some-id"
XCons:
receive_interface: "DST-some-id"
transmit_interface: "SRC-some-id"
LinuxInterfaces:
name: "SRC-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.2.1/30"
host_if_name: "if2_src"
namespace:
type: FILE_REF_NS
filepath: "/proc/13189/ns/net"
tap:
temp_if_name: "bid1ifss11g"
LinuxInterfaces:
name: "DST-some-id"
description: "Some description"
type: AUTO_TAP
enabled: true
ip_addresses: "10.30.2.2/30"
host_if_name: "if2_dst"
namespace:
type: FILE_REF_NS
filepath: "/proc/13418/ns/net"
tap:
temp_if_name: "bid1ifss120"
Raw
vpp-agent-logs--after-first.txt
time="2019-03-26 12:21:19.52164" level=info msg="Linux interface SRC-some-id with hostIfName if1_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-26 12:21:19.52202" level=info msg="Linux interface DST-some-id with hostIfName if1_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-26 12:21:19.54280" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-26 12:21:19.54891" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-26 12:21:19.55373" level=info msg="Interface SRC-some-id configured" loc="ifplugin/interface_config.go(320)" logger=vpp.if-conf
time="2019-03-26 12:21:19.58682" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-26 12:21:19.59588" level=warning msg="Unable to deliver the notification, reciever end not ready." msg_id=83 msg_name=sw_interface_event msg_size=17
time="2019-03-26 12:21:19.60054" level=info msg="Interface DST-some-id configured" loc="ifplugin/interface_config.go(320)" logger=vpp.if-conf
time="2019-03-26 12:21:19.60072" level=info msg="there is no linux tap configuration entry for interface bid1ifss11g" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-26 12:21:19.60420" level=info msg="L2 XConnect pair SRC-some-id-DST-some-id configured" loc="l2plugin/xconnect_config.go(126)" logger=vpp.xc-conf
time="2019-03-26 12:21:19.60654" level=info msg="L2 XConnect pair DST-some-id-SRC-some-id configured" loc="l2plugin/xconnect_config.go(126)" logger=vpp.xc-conf
time="2019-03-26 12:21:19.60674" level=debug msg="TX Done - all events callbacks received" loc="syncbase/done.go(79)" logger=defaultLogger
time="2019-03-26 12:21:19.60950" level=info msg="transport: loopyWriter.run returning. connection error: desc = "transport is closing"" loc="grpclog/logger.go(55)" logger=grpc.grpc-server
time="2019-03-26 12:21:19.63455" level=warning msg="Received rx-placement data for unknown interface with index 3" loc="vppcalls/dump_interface_vppcalls.go(299)" logger=vpp.if-state
time="2019-03-26 12:21:19.63640" level=info msg="Linux interface SRC-some-id with hostIfName if1_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-26 12:21:19.63677" level=info msg="Linux interface DST-some-id with hostIfName if1_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
Raw
vpp-agent-logs--after-second.txt
time="2019-03-26 12:21:24.81579" level=info msg="Linux interface if1_src removed" loc="ifplugin/interface_config.go(282)" logger=linux.if-conf
time="2019-03-26 12:21:24.86354" level=info msg="Linux interface SRC-some-id with hostIfName if2_src configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-26 12:21:24.90351" level=info msg="Linux interface if1_dst removed" loc="ifplugin/interface_config.go(282)" logger=linux.if-conf
time="2019-03-26 12:21:24.95169" level=info msg="Linux interface DST-some-id with hostIfName if2_dst configured" loc="ifplugin/interface_config.go(173)" logger=linux.if-conf
time="2019-03-26 12:21:24.95367" level=info msg="Interface SRC-some-id modified" loc="ifplugin/interface_config.go(468)" logger=vpp.if-conf
time="2019-03-26 12:21:24.95425" level=info msg="Interface DST-some-id modified" loc="ifplugin/interface_config.go(468)" logger=vpp.if-conf
time="2019-03-26 12:21:24.95597" level=info msg="L2 XConnect pair (rx: SRC-some-id) modified" loc="l2plugin/xconnect_config.go(173)" logger=vpp.xc-conf
time="2019-03-26 12:21:24.95687" level=info msg="L2 XConnect pair (rx: DST-some-id) modified" loc="l2plugin/xconnect_config.go(173)" logger=vpp.xc-conf
time="2019-03-26 12:21:24.95707" level=info msg="there is no linux tap configuration entry for interface bid1ifss11g" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-26 12:21:24.95707" level=debug msg="TX Done - all events callbacks received" loc="syncbase/done.go(79)" logger=defaultLogger
time="2019-03-26 12:21:24.95725" level=info msg="there is no linux tap configuration entry for interface bid1ifss120" loc="ifplugin/interface_config.go(351)" logger=linux.if-conf
time="2019-03-26 12:21:24.95919" level=info msg="transport: http2Server.HandleStreams failed to read frame: read tcp 127.0.0.1:9111->127.0.0.1:46948: read: connection reset by peer" loc="grpclog/logger.go(67)" logger=grpc.grpc-server
time="2019-03-26 12:21:24.95947" level=info msg="transport: loopyWriter.run returning. connection error: desc = "transport is closing"" loc="grpclog/logger.go(55)" logger=grpc.grpc-server
Raw
vppctl-sh-int--after-second.txt
Name Idx State MTU (L3/IP4/IP6/MPLS) Counter Count
host-eth0 1 up 9000/0/0/0 rx packets 5
rx bytes 266
drops 5
ip6 2
local0 0 down 0/0/0/0
tap0 2 up 9000/0/0/0 rx packets 6
rx bytes 364
tx packets 3
tx bytes 238
tap1 3 up 9000/0/0/0 rx packets 3
rx bytes 238
tx packets 6
tx bytes 364
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment