(continuation) Enable logs from chain elements regardless of EnableTracing #1489

glazychev-art · 2023-07-13T07:39:00Z

Description

This is continuation of - #1475
(see description there)

Example logs from forwarder with `DEBUG` log level

Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] Setting env variable DLV_LISTEN_FORWARDER to a valid dlv '--listen' value will cause the dlv debugger to execute this binary and listen as directed.
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] there are 9 phases which will be executed followed by a success message:
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] the phases include:
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 1: get config from environment
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 2: run vpp and get a connection to it
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 3: get SR-IOV config from file
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 4: init pools
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 5: start device plugin server
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 6: retrieve spiffe svid
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 7: create xconnect network service endpoint
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 8: create grpc server and register xconnect
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] 9: register xconnectns with the registry
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] a final success message with start time duration
Jul 13 07:15:46.402 [INFO] [cmd:/bin/forwarder] executing phase 1: get config from environment (time since start: 107.916µs)
This application is configured via the environment. The following environment
variables can be used:

KEY                             TYPE                                           DEFAULT                                                                               REQUIRED    DESCRIPTION
NSM_NAME                        String                                         forwarder                                                                                         Name of Endpoint
NSM_LABELS                      Comma-separated list of String:String pairs    p2p:true                                                                                          Labels related to this forwarder-vpp instance
NSM_NSNAME                      String                                         forwarder                                                                                         Name of Network Service to Register with Registry
NSM_CONNECT_TO                  URL                                            unix:///connect.to.socket                                                                         url to connect to
NSM_LISTEN_ON                   URL                                            unix:///listen.on.socket                                                                          url to listen on
NSM_MAX_TOKEN_LIFETIME          Duration                                       10m                                                                                               maximum lifetime of tokens
NSM_REGISTRY_CLIENT_POLICIES    Comma-separated list of String                 etc/nsm/opa/common/.*.rego,etc/nsm/opa/registry/.*.rego,etc/nsm/opa/client/.*.rego                paths to files and directories that contain registry client policies
NSM_LOG_LEVEL                   String                                         INFO                                                                                              Log level
NSM_DIAL_TIMEOUT                Duration                                       100ms                                                                                             Timeout for the dial the next endpoint
NSM_OPENTELEMETRYENDPOINT       String                                         otel-collector.observability.svc.cluster.local:4317                                               OpenTelemetry Collector Endpoint
NSM_TUNNEL_IP                   String                                                                                                                                           IP to use for tunnels
NSM_VXLAN_PORT                  Unsigned Integer                               0                                                                                                 VXLAN port to use
NSM_VPP_API_SOCKET              String                                         /var/run/vpp/external/vpp-api.sock                                                                filename of socket to connect to existing VPP instance.  If empty a VPP instance is run in forwarder
NSM_VPP_INIT                    Func                                           AF_PACKET                                                                                         type of VPP initialization. Must be AF_XDP, AF_PACKET or NONE
NSM_RESOURCE_POLL_TIMEOUT       Duration                                       30s                                                                                               device plugin polling timeout
NSM_DEVICE_PLUGIN_PATH          String                                         /var/lib/kubelet/device-plugins/                                                                  path to the device plugin directory
NSM_POD_RESOURCES_PATH          String                                         /var/lib/kubelet/pod-resources/                                                                   path to the pod resources directory
NSM_DEVICE_SELECTOR_FILE        String                                                                                                                                           config file for device name to label matching
NSM_SRIOV_CONFIG_FILE           String                                                                                                                                           PCI resources config path
NSM_PCI_DEVICES_PATH            String                                         /sys/bus/pci/devices                                                                              path to the PCI devices directory
NSM_PCI_DRIVERS_PATH            String                                         /sys/bus/pci/drivers                                                                              path to the PCI drivers directory
NSM_CGROUP_PATH                 String                                         /host/sys/fs/cgroup/devices                                                                       path to the host cgroup directory
NSM_VFIO_PATH                   String                                         /host/dev/vfio                                                                                    path to the host VFIO directory
NSM_MECHANISM_PRIORITY          Comma-separated list of String                                                                                                                   sets priorities for mechanisms
Jul 13 07:15:46.410 [INFO] [cmd:/bin/forwarder] Config: &config.Config{Name:"forwarder-vpp-fjqv6", Labels:map[string]string{"p2p":"true"}, NSName:"forwarder", ConnectTo:url.URL{Scheme:"unix", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/var/lib/networkservicemesh/nsm.io.sock", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}, ListenOn:url.URL{Scheme:"unix", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/listen.on.sock", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}, MaxTokenLifetime:600000000000, RegistryClientPolicies:[]string{"etc/nsm/opa/common/.*.rego", "etc/nsm/opa/registry/.*.rego", "etc/nsm/opa/client/.*.rego"}, LogLevel:"DEBUG", DialTimeout:100000000, OpenTelemetryEndpoint:"otel-collector.observability.svc.cluster.local:4317", TunnelIP:net.IP{0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0xff, 0xff, 0xac, 0x12, 0x0, 0x3}, VxlanPort:0x0, VppAPISocket:"/var/run/vpp/external/vpp-api.sock", VppInit:vppinit.Func{f:(func(context.Context, api.Connection, net.IP) (net.IP, error))(0xe394c0)}, ResourcePollTimeout:30000000000, DevicePluginPath:"/var/lib/kubelet/device-plugins/", PodResourcesPath:"/var/lib/kubelet/pod-resources/", DeviceSelectorFile:"", SRIOVConfigFile:"", PCIDevicesPath:"/sys/bus/pci/devices", PCIDriversPath:"/sys/bus/pci/drivers", CgroupPath:"/host/sys/fs/cgroup/devices", VFIOPath:"/host/dev/vfio", MechanismPriority:[]string(nil)}
Jul 13 07:15:46.410 [INFO] [cmd:/bin/forwarder] [duration:7.322845ms] completed phase 1: get config from environment
Jul 13 07:15:46.410 [INFO] [cmd:/bin/forwarder] executing phase 2: run vpp and get a connection to it (time since start: 7.468147ms)
Jul 13 07:15:46.410 [INFO] Configuration file: "/etc/vpp/helper/vpp.conf" not found, using defaults
Jul 13 07:15:46.410 [INFO] [cmd:/bin/forwarder] local vpp is being used
Jul 13 07:15:46.410 [INFO] [cmd:/bin/forwarder] [duration:882.197µs] completed phase 2: run vpp and get a connection to it
Jul 13 07:15:46.411 [WARN] [cmd:/bin/forwarder] skipping phases 3-5: no PCI resources config
Jul 13 07:15:46.411 [WARN] [cmd:/bin/forwarder] SR-IOV is not enabled
Jul 13 07:15:46.411 [INFO] [cmd:/bin/forwarder] executing phase 6: retrieving svid, check spire agent logs if this is the last line you see (time since start: 9.389553ms)
Jul 13 07:15:46.468 [INFO] [cmd:vpp] vpp[345236]: buffer: numa[0] falling back to non-hugepage backed buffer pool (vlib_physmem_shared_map_create: pmalloc_map_pages: Unable to lock pages: Cannot allocate memory)
Jul 13 07:15:46.770 [INFO] [cmd:vpp] vpp[345236]: vnet_feature_arc_init:272: feature node 'ip6-lookup' not found (before 'pt', arc 'ip6-output')
Jul 13 07:15:46.794 [DEBU] /var/run/vpp/api.sock was created after 383.883903ms
Jul 13 07:15:46.840 [DEBU] successfully connected to /var/run/vpp/api.sock after 45.663689ms and 1 attempts
Jul 13 07:15:57.013 [INFO] SVID: "spiffe://k8s.nsm/ns/nsm-system/pod/forwarder-vpp-fjqv6"
Jul 13 07:15:57.013 [INFO] [cmd:/bin/forwarder] [duration:10.601601426s] completed phase 6: retrieving svid
Jul 13 07:15:57.013 [INFO] [cmd:/bin/forwarder] executing phase 7: create xconnect network service endpoint (time since start: 10.611058405s)
Jul 13 07:15:57.094 [DEBU] [cmd:/bin/forwarder] [duration:79.63732ms] [flags:AF_PACKET_API_FLAG_VERSION_2] [hostIfName:eth0] [hwaddr:02:42:ac:12:00:03] [mode:AF_PACKET_API_MODE_ETHERNET] [swIfIndex:1] [vppapi:AfPacketCreateV3] completed
Jul 13 07:15:57.095 [DEBU] [MTU:[1500 1500 1500 1500]] [cmd:/bin/forwarder] [duration:487.492µs] [swIfIndex:1] [vppapi:SwInterfaceSetMtu] completed
Jul 13 07:15:57.095 [DEBU] [aclIndex:0] [cmd:/bin/forwarder] [duration:301.8µs] [vppapi:ACLAddReplace] completed
Jul 13 07:15:57.096 [DEBU] [aclIndex:1] [cmd:/bin/forwarder] [duration:295.624µs] [vppapi:ACLAddReplace] completed
Jul 13 07:15:57.150 [DEBU] [NInput:1] [acls:[0 1]] [cmd:/bin/forwarder] [duration:54.811494ms] [swIfIndex:1] [vppapi:ACLInterfaceSetACLList] completed
Jul 13 07:15:57.150 [DEBU] [cmd:/bin/forwarder] [duration:76.268µs] [swIfIndex:1] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:15:57.151 [DEBU] [cmd:/bin/forwarder] [duration:183.417µs] [ipAddress:172.18.0.2] [macAddress:02:42:ac:12:00:02] [swIfIndex:1] [vppapi:IPNeighborAddDel] completed
Jul 13 07:15:57.151 [DEBU] [cmd:/bin/forwarder] [duration:57.46µs] [ipAddress:172.18.0.4] [macAddress:02:42:ac:12:00:04] [swIfIndex:1] [vppapi:IPNeighborAddDel] completed
Jul 13 07:15:57.151 [INFO] [cmd:/bin/forwarder] host link was added as a neighbor: IP: 10.244.1.1, MAC: e2:d8:0a:ef:1d:64
Jul 13 07:15:57.151 [INFO] [cmd:/bin/forwarder] host link was added as a neighbor: IP: 10.244.1.1, MAC: ce:16:51:44:74:e1
Jul 13 07:15:57.151 [DEBU] [cmd:/bin/forwarder] [duration:289.964µs] [isAdd:true] [prefix:172.18.0.3/16] [swIfIndex:1] [vppapi:SwInterfaceAddDelAddress] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:110.646µs] [isAdd:true] [nh.address:172.18.0.1] [prefix:0.0.0.0/0] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:148.277µs] [isAdd:true] [nh.address:172.18.0.4] [prefix:10.244.0.0/24] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:36.656µs] [isAdd:true] [nh.address:172.18.0.2] [prefix:10.244.2.0/24] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:78.449µs] [isAdd:true] [nh.address:ac12:2::] [prefix:172.18.0.0/16] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:144.647µs] [isAdd:true] [nh.address:ac12:2::] [prefix:fc00:f853:ccd:e793::/64] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:55.963µs] [isAdd:true] [nh.address:ac12:2::] [prefix:fe80::/64] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.152 [DEBU] [cmd:/bin/forwarder] [duration:60.252µs] [isAdd:true] [nh.address:fc00:f853:ccd:e793::1] [prefix:::/0] [swIfIndex:1] [vppapi:IPRouteAddDel] completed
Jul 13 07:15:57.153 [INFO] [cmd:/bin/forwarder] [duration:139.328949ms] completed phase 7: create xconnect network service endpoint
Jul 13 07:15:57.153 [INFO] [cmd:/bin/forwarder] executing phase 8: create grpc server and register xconnect (time since start: 10.750423715s)
Jul 13 07:15:57.153 [INFO] [cmd:/bin/forwarder] [duration:138.018µs] completed phase 8: create grpc server and register xconnect
Jul 13 07:15:57.153 [INFO] [cmd:/bin/forwarder] executing phase 9: register forwarder with the registry (time since start: 10.750578433s)
Jul 13 07:15:57.153 [DEBU] [type:registry] passed clientURL: unix:///var/lib/networkservicemesh/nsm.io.sock
Jul 13 07:15:57.183 [DEBU] [type:registry] passed clientURL: unix:///var/lib/networkservicemesh/nsm.io.sock
Jul 13 07:15:57.185 [INFO] [cmd:/bin/forwarder] [duration:32.130892ms] completed phase 9: register forwarder with the registry
Jul 13 07:15:57.185 [INFO] [cmd:/bin/forwarder] Startup completed in 10.782921086s
Jul 13 07:16:26.999 [DEBU] [type:registry] passed clientURL: unix:///var/lib/networkservicemesh/nsm.io.sock
Jul 13 07:16:27.063 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] passed clientURL: unix:///proc/345182/fd/20
Jul 13 07:16:27.064 [INFO] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:338.096µs] [type:networkService] [vppapi:WantInterfaceEvents] completed
Jul 13 07:16:27.065 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIserver:request] [mechanism.DstIP:172.18.0.3] [mechanism.DstPort:4789] [type:networkService] set mechanism dst
Jul 13 07:16:27.065 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIserver:request] [type:networkService] [vni:7566498] vni generated and stored in metadata
Jul 13 07:16:27.075 [INFO] [cmd:vpp] vpp[345236]: vl_api_want_interface_events_t_handler:1636: pid 345182: already enabled...
Jul 13 07:16:27.076 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIclient:request] [mechSrcIp:172.18.0.3] [mechSrcPort:4789] [type:networkService] set mechanism src
Jul 13 07:16:27.144 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vxlan:addDel] not vxlan mechanism
Jul 13 07:16:27.144 [INFO] [cmd:/bin/forwarder] [component:netNsMonitor] [inodeURL:inode://4/4026534820] started
Jul 13 07:16:27.179 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [HostIfName:kernel2eth-f8f6] [HostNamespace:/proc/345182/fd/30] [TapFlags:TapFlags(0)] [duration:35.014879ms] [swIfIndex:2] [type:networkService] [vppapi:TapCreateV2] completed
time="2023-07-13T07:16:27Z" level=info msg="No subscription found for the notification message." msg_id=701 msg_size=19
Jul 13 07:16:27.180 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:672.099µs] [mode:RX_MODE_API_ADAPTIVE] [swIfIndex:2] [type:networkService] [vppapi:SwInterfaceSetRxMode] completed
Jul 13 07:16:27.180 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:179.76µs] [link.Name:kernel2eth-f8f6] [netlink:LinkByName] [type:networkService] completed
Jul 13 07:16:27.181 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [alias:client-f8f67e65-53a3-4a22-a51c-c21a703af98a] [duration:128.494µs] [link.Name:kernel2eth-f8f6] [netlink:LinkSetAlias] [type:networkService] completed
Jul 13 07:16:27.181 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:43.973µs] [link.Name:kernel2eth-f8f6] [netlink:LinkSetUp] [type:networkService] completed
Jul 13 07:16:27.181 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:310.11µs] [swIfIndex:2] [tag:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vppapi:SwInterfaceTagAddDel] completed
Jul 13 07:16:27.182 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:[1446 1446 1446 1446]] [SwIfIndex:2] [duration:208.884µs] [type:networkService] [vppapi:SwInterfaceSetMtu] completed
time="2023-07-13T07:16:27Z" level=info msg="No subscription found for the notification message." msg_id=701 msg_size=19
Jul 13 07:16:27.182 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:334.954µs] [swIfIndex:2] [type:networkService] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:16:27.184 [INFO] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] /proc/sys/net/ipv4/ping_group_range was set to 0 2147483647
Jul 13 07:16:27.185 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Addr:172.16.1.100/32] [duration:95.438µs] [link.Name:kernel2eth-f8f6] [netlink:AddrAdd] [type:networkService] completed
Jul 13 07:16:27.185 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [AddrUpdate.LinkAddress:{172.16.1.100 ffffffff}] [duration:31.036µs] [link.Name:kernel2eth-f8f6] [type:networkService] complete
Jul 13 07:16:27.185 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Dst:172.16.1.101/32] [Flags:0] [Gw:<nil>] [Scope:link] [duration:67.128µs] [link.Name:kernel2eth-f8f6] [netlink:RouteReplace] [type:networkService] completed
Jul 13 07:16:27.185 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Dst:172.16.1.101/32] [Flags:0] [Gw:<nil>] [Scope:universe] [duration:58.348µs] [link.Name:kernel2eth-f8f6] [netlink:RouteReplace] [type:networkService] completed
Jul 13 07:16:27.186 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:1446] [duration:196.782µs] [link.Name:kernel2eth-f8f6] [netlink:LinkSetMTU] [type:networkService] completed
Jul 13 07:16:27.187 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:730.425µs] [swIfIndex:1] [type:networkService] [vppapi:SwInterfaceDump] found interface with ip 172.18.0.3
Jul 13 07:16:27.188 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:508.637µs] [swIfIndex:1] [type:networkService] [vppapi:ACLInterfaceListDump] initiated
Jul 13 07:16:27.188 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [aclIndex:0] [duration:295.227µs] [type:networkService] [vppapi:ACLDump] completed
Jul 13 07:16:27.188 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [aclIndex:1] [duration:234.506µs] [type:networkService] [vppapi:ACLDump] completed
Jul 13 07:16:27.189 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [aclIndex:2] [duration:899.914µs] [type:networkService] [vppapi:ACLAddReplace] completed
Jul 13 07:16:27.190 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [aclIndex:3] [duration:330.125µs] [type:networkService] [vppapi:ACLAddReplace] completed
Jul 13 07:16:27.191 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [NInput:2] [acls:[2 0 3 1]] [duration:673.237µs] [swIfIndex:1] [type:networkService] [vppapi:ACLInterfaceSetACLList] completed
Jul 13 07:16:27.193 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [NextIndex:3] [NextName:ethernet-input] [NodeName:vxlan4-input] [duration:2.010849ms] [isAdd:true] [type:networkService] [vppapi:AddNodeNext] completed
time="2023-07-13T07:16:27Z" level=info msg="No subscription found for the notification message." msg_id=701 msg_size=19
Jul 13 07:16:27.194 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [DstAddress:172.18.0.2] [SrcAddress:172.18.0.3] [Vni:7566498] [duration:1.013328ms] [isAdd:true] [swIfIndex:3] [type:networkService] [vppapi:VxlanAddDelTunnel] completed
Jul 13 07:16:27.195 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vxlan:addDel] not vxlan mechanism
Jul 13 07:16:27.195 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:[1446 1446 1446 1446]] [SwIfIndex:3] [duration:223.963µs] [type:networkService] [vppapi:SwInterfaceSetMtu] completed
Jul 13 07:16:27.195 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:194.941µs] [swIfIndex:3] [tag:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vppapi:SwInterfaceTagAddDel] completed
Jul 13 07:16:27.261 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Enable:true] [RxSwIfIndex:2] [TxSwIfIndex:3] [duration:66.101756ms] [type:networkService] [vppapi:SwInterfaceSetL2Xconnect] completed
Jul 13 07:16:27.262 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Enable:true] [RxSwIfIndex:3] [TxSwIfIndex:2] [duration:145.633µs] [type:networkService] [vppapi:SwInterfaceSetL2Xconnect] completed
Jul 13 07:16:27.262 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:157.519µs] [swIfIndex:2] [type:networkService] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:16:27.262 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:122.982µs] [swIfIndex:3] [type:networkService] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:16:29.186 [DEBU] [type:registry] passed clientURL: unix:///var/lib/networkservicemesh/nsm.io.sock
Jul 13 07:16:29.193 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] passed clientURL: unix:///proc/345182/fd/20
Jul 13 07:16:29.193 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIserver:request] [mechanism.DstIP:172.18.0.3] [mechanism.DstPort:4789] [type:networkService] set mechanism dst
Jul 13 07:16:29.193 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIserver:request] [type:networkService] [vni:7566498] loadOrStore vni in metadata
Jul 13 07:16:29.195 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [VNIclient:request] [mechSrcIp:172.18.0.3] [mechSrcPort:4789] [type:networkService] set mechanism src
Jul 13 07:16:29.201 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vxlan:addDel] not vxlan mechanism
Jul 13 07:16:29.201 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:124.331µs] [swIfIndex:2] [tag:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vppapi:SwInterfaceTagAddDel] completed
Jul 13 07:16:29.201 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:[1446 1446 1446 1446]] [SwIfIndex:2] [duration:37.368µs] [type:networkService] [vppapi:SwInterfaceSetMtu] completed
Jul 13 07:16:29.201 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:24.057µs] [swIfIndex:2] [type:networkService] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:16:29.202 [INFO] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] /proc/sys/net/ipv4/ping_group_range was set to 0 2147483647
Jul 13 07:16:30.207 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Dst:172.16.1.101/32] [Flags:0] [Gw:<nil>] [Scope:link] [duration:79.849µs] [link.Name:kernel2eth-f8f6] [netlink:RouteReplace] [type:networkService] completed
Jul 13 07:16:30.207 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Dst:172.16.1.101/32] [Flags:0] [Gw:<nil>] [Scope:universe] [duration:61.891µs] [link.Name:kernel2eth-f8f6] [netlink:RouteReplace] [type:networkService] completed
Jul 13 07:16:30.207 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:1446] [duration:31.382µs] [link.Name:kernel2eth-f8f6] [netlink:LinkSetMTU] [type:networkService] completed
Jul 13 07:16:30.208 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [MTU:[1446 1446 1446 1446]] [SwIfIndex:3] [duration:287.541µs] [type:networkService] [vppapi:SwInterfaceSetMtu] completed
Jul 13 07:16:30.208 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:401.779µs] [swIfIndex:3] [tag:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [type:networkService] [vppapi:SwInterfaceTagAddDel] completed
Jul 13 07:16:30.209 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Enable:true] [RxSwIfIndex:2] [TxSwIfIndex:3] [duration:333.075µs] [type:networkService] [vppapi:SwInterfaceSetL2Xconnect] completed
Jul 13 07:16:30.209 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [Enable:true] [RxSwIfIndex:3] [TxSwIfIndex:2] [duration:184.321µs] [type:networkService] [vppapi:SwInterfaceSetL2Xconnect] completed
Jul 13 07:16:30.209 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:208.866µs] [swIfIndex:2] [type:networkService] [vppapi:SwInterfaceSetFlags] completed
Jul 13 07:16:30.210 [DEBU] [id:f9af5c1a-a65e-4cda-9243-fb662810b0cf] [duration:209.238µs] [swIfIndex:3] [type:networkService] [vppapi:SwInterfaceSetFlags] completed

Issue link

Closes: #1475
networkservicemesh/deployments-k8s#9242

How Has This Been Tested?

Added unit testing to cover
Tested manually
Tested by integration testing
Have not tested

Types of changes

Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> always inject logger into context Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> fix copyright Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> fix race condition Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru>

Signed-off-by: Artem Glazychev <artem.glazychev@xored.com>

codecov · 2023-07-13T07:44:28Z

Codecov Report

❗ No coverage uploaded for pull request base (main@01bb35f). Click here to learn what that means.
Patch has no changes to coverable lines.

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #1489   +/-   ##
=======================================
  Coverage        ?   70.35%           
=======================================
  Files           ?      248           
  Lines           ?    11201           
  Branches        ?        0           
=======================================
  Hits            ?     7880           
  Misses          ?     2820           
  Partials        ?      501

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

…k@main PR link: networkservicemesh/sdk#1489 Commit: eaf1d25 Author: Artem Glazychev Date: 2023-07-13 15:43:22 +0700 Message: - (continuation) Enable logs from chain elements regardless of EnableTracing (#1489) * make IsTracingEnabled independent from log level Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> always inject logger into context Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> fix copyright Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> fix race condition Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> * Add fixes for registry, dns Signed-off-by: Artem Glazychev <artem.glazychev@xored.com> --------- Signed-off-by: Danil Uzlov <DanilUzlov@yandex.ru> Signed-off-by: Artem Glazychev <artem.glazychev@xored.com> Signed-off-by: NSMBot <nsmbot@networkservicmesh.io>

d-uzlov and others added 2 commits July 13, 2023 14:28

Add fixes for registry, dns

d8321eb

Signed-off-by: Artem Glazychev <artem.glazychev@xored.com>

glazychev-art force-pushed the log-level branch from 56bb43f to d8321eb Compare July 13, 2023 07:42

denis-tingaikin approved these changes Jul 13, 2023

View reviewed changes

denis-tingaikin merged commit eaf1d25 into networkservicemesh:main Jul 13, 2023

glazychev-art self-assigned this Jul 13, 2023

denis-tingaikin mentioned this pull request Jul 18, 2023

Missing log printouts in forwarder-vpp at DEBUG log level networkservicemesh/deployments-k8s#9242

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

(continuation) Enable logs from chain elements regardless of EnableTracing #1489

(continuation) Enable logs from chain elements regardless of EnableTracing #1489

glazychev-art commented Jul 13, 2023

codecov bot commented Jul 13, 2023 •

edited

Loading

(continuation) Enable logs from chain elements regardless of EnableTracing #1489

(continuation) Enable logs from chain elements regardless of EnableTracing #1489

Conversation

glazychev-art commented Jul 13, 2023

Description

Issue link

How Has This Been Tested?

Types of changes

codecov bot commented Jul 13, 2023 • edited Loading

Codecov Report

codecov bot commented Jul 13, 2023 •

edited

Loading