Uploaded image for project: 'Fast Datapath Product'
  1. Fast Datapath Product
  2. FDP-1123

[ovs3.5][vhost]VHOST_FDMAN: could not remove 62 fd from 63 epfd: No such file or directory

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Normal Normal
    • None
    • FDP-25.A
    • openvswitch3.5
    • 3
    • False
    • Hide

      None

      Show
      None
    • False
    • Hide

      Given a VM with a vhost-user server interface connected to OVS 3.5,

      When the VM is destroyed or shut down,

      Then, no VHOST_FDMAN errors appear in OVS logs.

      Show
      Given a VM with a vhost-user server interface connected to OVS 3.5, When the VM is destroyed or shut down, Then, no VHOST_FDMAN errors appear in OVS logs.
    • rhel-9
    • rhel-sst-network-fastdatapath
    • ssg_networking
    • OVS/DPDK - FDP-25.B
    • 1
    • Moderate

       Problem Description: Clearly explain the issue.

      after destroy guest with vhostuserserver port. ovs raise err log as below:

      VHOST_FDMAN: could not remove 62 fd from 63 epfd: No such file or directory

      This issue can't be reproduced on FDP25.A ovs3.1/3.3/3.4. I use the same Distro and the same guest configuration and only hit on ovs3.5.

       Impact Assessment: Describe the severity and impact (e.g., network down,availability of a workaround, etc.).

      ovs-vswitchd.log print err log

       Software Versions: Specify the exact versions in use (e.g.,openvswitch3.1-3.1.0-147.el8fdp).

       

        Issue Type: Indicate whether this is a new issue or a regression (if a regression, state the last known working version).

      new issue for ovs3.5, test on ovs3.1/3.3/3.4 and didn't hit this issue.

       Reproducibility: Confirm if the issue can be reproduced consistently. If not, describe how often it occurs.

      100%

       Reproduction Steps: Provide detailed steps or scripts to replicate the issue.

      1.create vhostuserclient port on ovs bridge

      ovs-vsctl list bridge 2>/dev/null | grep name | awk '{
    system("ovs-vsctl --if-exist del-br "$3" &>/dev/null")
}'
sleep 1
systemctl stop openvswitch &>/dev/null
sleep 1
rm -rf /etc/openvswitch/*.db
sleep 1
rm -rf /var/lib/openvswitch/*
sleep 1
rm -rf /dev/hugepages/rtemap_*
sleep 1
systemctl restart openvswitch &>/dev/null

ovs-vsctl set Open_vSwitch . other_config:dpdk-socket-mem=4096
ovs-vsctl set Open_vSwitch . other_config:vhost-iommu-support=true
ovs-vsctl set Open_vSwitch . other_config:dpdk-init=true
ovs-vsctl --may-exist add-br ovsbr2 -- set bridge ovsbr2 datapath_type=netdev
ovs-vsctl add-port ovsbr2 vhost0 -- set Interface vhost0 type=dpdkvhostuserclient options:vhost-server-path=/tmp/vhost0 mtu_request=9200

      2. define a guest xml that container vhostuserserver port.

      <domain type='kvm'>
  <name>g1</name>
  <memory unit='KiB'>8388608</memory>
  <currentMemory unit='KiB'>8388608</currentMemory>
  <memoryBacking>
    <hugepages>
      <page size='1048576' unit='KiB'/>
    </hugepages>
    <locked/>
    <access mode='shared'/>
  </memoryBacking>
  <vcpu placement='static'>3</vcpu>
  <cputune>
    <vcpupin vcpu='0' cpuset='8'/>
    <vcpusched vcpus='0' scheduler='fifo' priority='1'/>
    <vcpupin vcpu='1' cpuset='6'/>
    <vcpusched vcpus='1' scheduler='fifo' priority='1'/>
    <vcpupin vcpu='2' cpuset='4'/>
    <vcpusched vcpus='2' scheduler='fifo' priority='1'/>
    <emulatorsched scheduler='fifo' priority='1'/>
    <emulatorpin cpuset='2'/>
  </cputune>
  <numatune>
    <memory mode='strict' nodeset='0'/>
    <memnode cellid='0' mode='strict' nodeset='0'/>
  </numatune>
  <resource>
    <partition>/machine</partition>
  </resource>
  <os>
    <type arch='x86_64' machine='q35'>hvm</type>
    <boot dev='hd'/>
  </os>
  <features>
    <acpi/>
    <pmu state='off'/>
    <vmport state='off'/>
    <ioapic driver='qemu'/>
  </features>
  <cpu mode='host-passthrough' check='none'>
    <feature policy='require' name='tsc-deadline'/>
    <numa>
      <cell id='0' cpus='0-2' memory='8388608' unit='KiB' memAccess='shared'/>
    </numa>
  </cpu>
  <clock offset='utc'>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>restart</on_crash>
  <pm>
    <suspend-to-mem enabled='no'/>
    <suspend-to-disk enabled='no'/>
  </pm>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2'/>
      <source file='/var/lib/libvirt/images/g1.qcow2'/>
      <backingStore/>
      <target dev='vda' bus='virtio'/>
      <alias name='virtio-disk0'/>
      <address type='pci' domain='0x0000' bus='0x01' slot='0x00' function='0x0'/>
    </disk>
    <controller type='usb' index='0' model='none'>
      <alias name='usb'/>
    </controller>
    <controller type='pci' index='0' model='pcie-root'>
      <alias name='pcie.0'/>
    </controller>
    <controller type='pci' index='1' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='1' port='0x10'/>
      <alias name='pci.1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </controller>
    <controller type='pci' index='2' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='2' port='0x11'/>
      <alias name='pci.2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </controller>
    <controller type='pci' index='3' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='3' port='0x8'/>
      <alias name='pci.3'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </controller>
    <controller type='pci' index='4' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='4' port='0x9'/>
      <alias name='pci.4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </controller>
    <controller type='pci' index='5' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='5' port='0xa'/>
      <alias name='pci.5'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x06' function='0x0'/>
    </controller>
    <controller type='pci' index='6' model='pcie-root-port'>
      <model name='pcie-root-port'/>
      <target chassis='6' port='0xb'/>
      <alias name='pci.6'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x07' function='0x0'/>
    </controller>
    <controller type='sata' index='0'>
      <alias name='ide'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x1f' function='0x2'/>
    </controller>
    <interface type='bridge'>
      <mac address='52:54:00:01:02:03'/>
      <source bridge='virbr0'/>
      <model type='virtio'/>
    </interface>
    <interface type='vhostuser'>
      <mac address='00:de:ad:00:00:01'/>
      <source type='unix' path='/tmp/vhost0' mode='server'/>
      <model type='virtio'/>
      <driver name='vhost' queues='1' rx_queue_size='1024' tx_queue_size='1024' iommu='off' ats='off'>
  <host mrg_rxbuf='off'/>
  </driver>
      <address type='pci' domain='0x0000' bus='0x03' slot='0x00' function='0x0'/>
    </interface>
    <serial type='pty'>
      <source path='/dev/pts/1'/>
      <target type='isa-serial' port='0'>
        <model name='isa-serial'/>
      </target>
      <alias name='serial0'/>
    </serial>
    <console type='pty' tty='/dev/pts/1'>
      <source path='/dev/pts/1'/>
      <target type='serial' port='0'/>
      <alias name='serial0'/>
    </console>
    <input type='mouse' bus='ps2'>
      <alias name='input0'/>
    </input>
    <input type='keyboard' bus='ps2'>
      <alias name='input1'/>
    </input>
    <graphics type='vnc' port='5900' autoport='yes' listen='0.0.0.0'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <memballoon model='virtio'>
      <alias name='balloon0'/>
      <address type='pci' domain='0x0000' bus='0x06' slot='0x00' function='0x0'/>
    </memballoon>
    <iommu model='intel'>
      <driver intremap='on' caching_mode='on' iotlb='on'/>
    </iommu>
  </devices>
</domain>

      3. create guest and destroy guest

      virsh create g1.xml

      virsh destroy g1

       Expected Behavior: Describe what should happen under normal circumstances.

      no err message print on ovs-vswitchd.log

       Observed Behavior: Explain what actually happens.

      ovs-vswitchd.log print below err message

      2025-01-29T11:28:47.436Z|00100|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vhost-user client: socket created, fd: 62
2025-01-29T11:28:47.436Z|00101|dpdk|WARN|VHOST_CONFIG: (/tmp/vhost0) failed to connect: No such file or directory
2025-01-29T11:28:47.436Z|00102|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) reconnecting...
2025-01-29T11:28:47.436Z|00103|dpdk|ERR|VHOST_FDMAN: could not remove 62 fd from 63 epfd: No such file or directory

       Troubleshooting Actions: Outline the steps taken to diagnose or resolve the issue so far.

      This issue happened on performance testing and I was able to reproduce it.

       Logs: If you collected logs please provide them (e.g. sos report, /var/log/openvswitch/* , testpmd console)

      full of openvswitch log

      2025-01-29T11:07:07.985Z|00005|reconnect|INFO|unix:/var/run/openvswitch/db.sock: connecting...
2025-01-29T11:07:07.985Z|00006|reconnect|INFO|unix:/var/run/openvswitch/db.sock: connected
2025-01-29T11:07:07.987Z|00007|dpdk|INFO|Using DPDK 24.11.1
2025-01-29T11:07:07.987Z|00008|dpdk|INFO|DPDK Enabled - initializing...
2025-01-29T11:07:07.987Z|00009|dpdk|INFO|EAL ARGS: ovs-vswitchd -c 0x100000000 --socket-mem 4096 --in-memory.
2025-01-29T11:07:07.991Z|00010|dpdk|INFO|EAL: Detected CPU lcores: 40
2025-01-29T11:07:07.991Z|00011|dpdk|INFO|EAL: Detected NUMA nodes: 2
2025-01-29T11:07:07.992Z|00012|dpdk|INFO|EAL: Detected static linkage of DPDK
2025-01-29T11:07:08.013Z|00013|dpdk|INFO|EAL: rte_mem_virt2phy(): cannot open /proc/self/pagemap: Permission denied
2025-01-29T11:07:08.013Z|00014|dpdk|INFO|EAL: Selected IOVA mode 'VA'
2025-01-29T11:07:08.013Z|00015|dpdk|WARN|EAL: No free 2048 kB hugepages reported on node 0
2025-01-29T11:07:08.013Z|00016|dpdk|WARN|EAL: No free 2048 kB hugepages reported on node 1
2025-01-29T11:07:08.014Z|00017|dpdk|INFO|EAL: VFIO support initialized
2025-01-29T11:07:08.885Z|00018|dpdk|INFO|EAL: Using IOMMU type 1 (Type 1)
2025-01-29T11:07:09.499Z|00019|netdev_dpdk|INFO|Per port memory for DPDK devices disabled.
2025-01-29T11:07:09.499Z|00020|netdev_dpdk|INFO|No vhost-sock-dir provided - defaulting to /var/run/openvswitch
2025-01-29T11:07:09.499Z|00021|netdev_dpdk|INFO|IOMMU support for vhost-user-client enabled.
2025-01-29T11:07:09.499Z|00022|netdev_dpdk|INFO|POSTCOPY support for vhost-user-client disabled.
2025-01-29T11:07:09.502Z|00023|dpdk|INFO|DPDK Enabled - initialized
2025-01-29T11:07:09.505Z|00024|pmd_perf|INFO|DPDK provided TSC frequency: 2294600 KHz
2025-01-29T11:07:09.506Z|00025|dpif_netdev_extract|INFO|Default MFEX Extract implementation is scalar.
2025-01-29T11:07:09.506Z|00026|dpif_netdev_impl|INFO|Default DPIF implementation is dpif_scalar.
2025-01-29T11:07:09.515Z|00027|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports recirculation
2025-01-29T11:07:09.515Z|00028|ofproto_dpif|INFO|netdev@ovs-netdev: VLAN header stack length probed as 1
2025-01-29T11:07:09.515Z|00029|ofproto_dpif|INFO|netdev@ovs-netdev: MPLS label stack length probed as 3
2025-01-29T11:07:09.515Z|00030|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports truncate action
2025-01-29T11:07:09.515Z|00031|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports unique flow ids
2025-01-29T11:07:09.515Z|00032|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports clone action
2025-01-29T11:07:09.515Z|00033|ofproto_dpif|INFO|netdev@ovs-netdev: Max sample nesting level probed as 10
2025-01-29T11:07:09.515Z|00034|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports eventmask in conntrack action
2025-01-29T11:07:09.515Z|00035|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_clear action
2025-01-29T11:07:09.515Z|00036|ofproto_dpif|INFO|netdev@ovs-netdev: Max dp_hash algorithm probed to be 1
2025-01-29T11:07:09.515Z|00037|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports check_pkt_len action
2025-01-29T11:07:09.515Z|00038|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports timeout policy in conntrack action
2025-01-29T11:07:09.515Z|00039|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports explicit drop action
2025-01-29T11:07:09.515Z|00040|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_zero_snat
2025-01-29T11:07:09.515Z|00041|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports add_mpls action
2025-01-29T11:07:09.515Z|00042|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath does not support psample action
2025-01-29T11:07:09.515Z|00043|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_state
2025-01-29T11:07:09.515Z|00044|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_zone
2025-01-29T11:07:09.515Z|00045|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_mark
2025-01-29T11:07:09.515Z|00046|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_label
2025-01-29T11:07:09.515Z|00047|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_state_nat
2025-01-29T11:07:09.515Z|00048|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_orig_tuple
2025-01-29T11:07:09.515Z|00049|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_orig_tuple6
2025-01-29T11:07:09.515Z|00050|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports IPv6 ND Extensions
2025-01-29T11:07:09.515Z|00051|ofproto_dpif_upcall|INFO|Overriding n-handler-threads to 0, setting n-revalidator-threads to 1
2025-01-29T11:07:09.515Z|00052|ofproto_dpif_upcall|INFO|Starting 1 threads
2025-01-29T11:07:09.517Z|00053|dpif_netdev|INFO|pmd-rxq-affinity isolates PMD core
2025-01-29T11:07:09.517Z|00054|dpif_netdev|INFO|PMD auto load balance interval set to 1 mins
2025-01-29T11:07:09.517Z|00055|dpif_netdev|INFO|PMD auto load balance improvement threshold set to 25%
2025-01-29T11:07:09.517Z|00056|dpif_netdev|INFO|PMD auto load balance load threshold set to 95%
2025-01-29T11:07:09.517Z|00057|dpif_netdev|INFO|PMD auto load balance is disabled.
2025-01-29T11:07:09.517Z|00058|dpif_netdev|INFO|Default PMD thread max sleep:    0 us.
2025-01-29T11:07:09.517Z|00059|bridge|INFO|bridge ovsbr1: added interface ovsbr1 on port 65534
2025-01-29T11:07:09.517Z|00060|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 36, max sleep:    0 us.
2025-01-29T11:07:09.517Z|00061|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 36 created.
2025-01-29T11:07:09.517Z|00062|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 34, max sleep:    0 us.
2025-01-29T11:07:09.517Z|00063|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 34 created.
2025-01-29T11:07:09.517Z|00064|dpif_netdev|INFO|There are 2 pmd threads on numa node 0
2025-01-29T11:07:09.517Z|00065|dpdk|INFO|ETHDEV: Device with port_id=0 already stopped
2025-01-29T11:07:09.524Z|00001|dpdk(pmd-c34/id:4)|INFO|PMD thread uses DPDK lcore 0.
2025-01-29T11:07:09.528Z|00001|dpdk(pmd-c36/id:6)|INFO|PMD thread uses DPDK lcore 1.
2025-01-29T11:07:10.524Z|00001|ovs_rcu(urcu3)|WARN|blocked 1000 ms waiting for main to quiesce
2025-01-29T11:07:10.615Z|00066|netdev_dpdk|INFO|Port 0: 40:a6:b7:3e:a5:60
2025-01-29T11:07:10.615Z|00067|netdev_dpdk|INFO|dpdk0: rx-steering: default rss
2025-01-29T11:07:10.615Z|00068|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:07:10.615Z|00069|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:07:10.615Z|00070|bridge|INFO|bridge ovsbr1: added interface dpdk0 on port 1
2025-01-29T11:07:10.615Z|00071|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:07:10.615Z|00072|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:07:10.615Z|00073|bridge|INFO|bridge ovsbr2: added interface ovsbr2 on port 65534
2025-01-29T11:07:10.615Z|00074|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:07:10.615Z|00075|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:07:10.615Z|00076|bridge|INFO|bridge ovsbr2: added interface gre0 on port 2
2025-01-29T11:07:10.616Z|00077|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) Linear buffers requested without external buffers,
2025-01-29T11:07:10.616Z|00078|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) disabling host segmentation offloading support
2025-01-29T11:07:10.616Z|00079|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vhost-user client: socket created, fd: 62
2025-01-29T11:07:10.616Z|00080|netdev_dpdk|INFO|vHost User device 'vhost0' created in 'client' mode, using client socket '/tmp/vhost0'
2025-01-29T11:07:10.634Z|00081|dpdk|WARN|VHOST_CONFIG: (/tmp/vhost0) failed to connect: Permission denied
2025-01-29T11:07:10.634Z|00082|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) reconnecting...
2025-01-29T11:07:10.634Z|00083|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:07:10.634Z|00084|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:07:10.634Z|00085|dpif_netdev|INFO|Core 36 on numa node 0 assigned port 'vhost0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:07:10.634Z|00086|bridge|INFO|bridge ovsbr2: added interface vhost0 on port 1
2025-01-29T11:07:10.634Z|00087|bridge|INFO|bridge ovsbr1: using datapath ID 000040a6b73ea560
2025-01-29T11:07:10.634Z|00088|connmgr|INFO|ovsbr1: added service controller "punix:/var/run/openvswitch/ovsbr1.mgmt"
2025-01-29T11:07:10.634Z|00089|bridge|INFO|bridge ovsbr2: using datapath ID 00000aabe8a4d34d
2025-01-29T11:07:10.634Z|00090|connmgr|INFO|ovsbr2: added service controller "punix:/var/run/openvswitch/ovsbr2.mgmt"
2025-01-29T11:07:10.636Z|00091|timeval|WARN|Unreasonably long 2650ms poll interval (1091ms user, 832ms system)
2025-01-29T11:07:10.636Z|00092|timeval|WARN|faults: 5051 minor, 0 major
2025-01-29T11:07:10.636Z|00093|timeval|WARN|disk: 0 reads, 16 writes
2025-01-29T11:07:10.636Z|00094|timeval|WARN|context switches: 1186 voluntary, 914 involuntary
2025-01-29T11:07:10.636Z|00095|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour,  hash=c62031ed:
2025-01-29T11:07:10.636Z|00096|coverage|INFO|route_table_dump           0.0/sec     0.000/sec        0.0000/sec   total: 2
2025-01-29T11:07:10.636Z|00097|coverage|INFO|netlink_sent               0.0/sec     0.000/sec        0.0000/sec   total: 127
2025-01-29T11:07:10.636Z|00098|coverage|INFO|netlink_recv_jumbo         0.0/sec     0.000/sec        0.0000/sec   total: 30
2025-01-29T11:07:10.636Z|00099|coverage|INFO|netlink_received           0.0/sec     0.000/sec        0.0000/sec   total: 142
2025-01-29T11:07:10.636Z|00100|coverage|INFO|netdev_get_ethtool         0.0/sec     0.000/sec        0.0000/sec   total: 4
2025-01-29T11:07:10.636Z|00101|coverage|INFO|netdev_set_policing        0.0/sec     0.000/sec        0.0000/sec   total: 2
2025-01-29T11:07:10.636Z|00102|coverage|INFO|util_xalloc                0.0/sec     0.000/sec        0.0000/sec   total: 14130
2025-01-29T11:07:10.636Z|00103|coverage|INFO|stream_open                0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00104|coverage|INFO|pstream_open               0.0/sec     0.000/sec        0.0000/sec   total: 5
2025-01-29T11:07:10.636Z|00105|coverage|INFO|seq_change                 0.0/sec     0.000/sec        0.0000/sec   total: 1761
2025-01-29T11:07:10.636Z|00106|coverage|INFO|poll_zero_timeout          0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00107|coverage|INFO|poll_create_node           0.0/sec     0.000/sec        0.0000/sec   total: 119
2025-01-29T11:07:10.636Z|00108|coverage|INFO|txn_incomplete             0.0/sec     0.000/sec        0.0000/sec   total: 2
2025-01-29T11:07:10.636Z|00109|coverage|INFO|txn_unchanged              0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00110|coverage|INFO|netdev_get_stats           0.0/sec     0.000/sec        0.0000/sec   total: 10
2025-01-29T11:07:10.636Z|00111|coverage|INFO|netdev_received            0.0/sec     0.000/sec        0.0000/sec   total: 2
2025-01-29T11:07:10.636Z|00112|coverage|INFO|hmap_shrink                0.0/sec     0.000/sec        0.0000/sec   total: 4
2025-01-29T11:07:10.636Z|00113|coverage|INFO|hmap_expand                0.0/sec     0.000/sec        0.0000/sec   total: 617
2025-01-29T11:07:10.636Z|00114|coverage|INFO|hmap_pathological          0.0/sec     0.000/sec        0.0000/sec   total: 6
2025-01-29T11:07:10.636Z|00115|coverage|INFO|miniflow_malloc            0.0/sec     0.000/sec        0.0000/sec   total: 81
2025-01-29T11:07:10.636Z|00116|coverage|INFO|flow_extract               0.0/sec     0.000/sec        0.0000/sec   total: 4
2025-01-29T11:07:10.636Z|00117|coverage|INFO|dpif_port_add              0.0/sec     0.000/sec        0.0000/sec   total: 5
2025-01-29T11:07:10.636Z|00118|coverage|INFO|dpif_flow_put_error        0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00119|coverage|INFO|dpif_flow_put              0.0/sec     0.000/sec        0.0000/sec   total: 26
2025-01-29T11:07:10.636Z|00120|coverage|INFO|dpif_flow_get              0.0/sec     0.000/sec        0.0000/sec   total: 25
2025-01-29T11:07:10.636Z|00121|coverage|INFO|dpif_flow_flush            0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00122|coverage|INFO|dpif_flow_del              0.0/sec     0.000/sec        0.0000/sec   total: 25
2025-01-29T11:07:10.636Z|00123|coverage|INFO|dpif_execute               0.0/sec     0.000/sec        0.0000/sec   total: 6
2025-01-29T11:07:10.636Z|00124|coverage|INFO|datapath_drop_upcall_error   0.0/sec     0.000/sec        0.0000/sec   total: 3
2025-01-29T11:07:10.636Z|00125|coverage|INFO|cmap_shrink                0.0/sec     0.000/sec        0.0000/sec   total: 39
2025-01-29T11:07:10.636Z|00126|coverage|INFO|cmap_expand                0.0/sec     0.000/sec        0.0000/sec   total: 69
2025-01-29T11:07:10.636Z|00127|coverage|INFO|ccmap_shrink               0.0/sec     0.000/sec        0.0000/sec   total: 27
2025-01-29T11:07:10.636Z|00128|coverage|INFO|rev_flow_table             0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00129|coverage|INFO|ofproto_update_port        0.0/sec     0.000/sec        0.0000/sec   total: 5
2025-01-29T11:07:10.636Z|00130|coverage|INFO|ofproto_flush              0.0/sec     0.000/sec        0.0000/sec   total: 2
2025-01-29T11:07:10.636Z|00131|coverage|INFO|bridge_reconfigure         0.0/sec     0.000/sec        0.0000/sec   total: 1
2025-01-29T11:07:10.636Z|00132|coverage|INFO|131 events never hit
2025-01-29T11:07:10.637Z|00133|bridge|INFO|ovs-vswitchd (Open vSwitch) 3.5.0-0.9.el9fdp
2025-01-29T11:07:11.140Z|00134|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:11.640Z|00135|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:11.662Z|00136|poll_loop|INFO|wakeup due to [POLLIN] on fd 61 (character device /dev/net/tun) at ../lib/netdev-linux.c:1578 (62% CPU usage)
2025-01-29T11:07:11.662Z|00137|poll_loop|INFO|wakeup due to 0-ms timeout at ../ofproto/ofproto-dpif.c:2134 (62% CPU usage)
2025-01-29T11:07:11.662Z|00138|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../lib/ovs-rcu.c:236 (62% CPU usage)
2025-01-29T11:07:11.662Z|00139|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../lib/ovs-rcu.c:236 (62% CPU usage)
2025-01-29T11:07:12.163Z|00140|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:12.663Z|00141|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:13.163Z|00142|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:13.664Z|00143|poll_loop|INFO|wakeup due to [POLLIN] on fd 68 (FIFO pipe:[114503]) at ../vswitchd/bridge.c:425 (62% CPU usage)
2025-01-29T11:07:18.006Z|00144|memory|INFO|58388 kB peak resident set size after 10.0 seconds
2025-01-29T11:07:18.006Z|00145|memory|INFO|idl-cells-Open_vSwitch:346 ports:5 revalidators:1 rules:10 udpif keys:1
2025-01-29T11:26:50.199Z|00146|bridge|INFO|bridge ovsbr2: deleted interface ovsbr2 on port 65534
2025-01-29T11:26:50.199Z|00147|bridge|INFO|bridge ovsbr2: deleted interface vhost0 on port 1
2025-01-29T11:26:50.199Z|00148|bridge|INFO|bridge ovsbr2: deleted interface gre0 on port 2
2025-01-29T11:26:50.200Z|00149|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:26:50.200Z|00150|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:26:50.201Z|00151|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:26:50.201Z|00152|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:26:50.256Z|00153|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:26:50.256Z|00154|dpif_netdev|INFO|Core 34 on numa node 0 assigned port 'dpdk0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:26:50.263Z|00155|bridge|INFO|bridge ovsbr1: deleted interface ovsbr1 on port 65534
2025-01-29T11:26:50.263Z|00156|bridge|INFO|bridge ovsbr1: deleted interface dpdk0 on port 1
2025-01-29T11:26:50.263Z|00157|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 36 destroyed.
2025-01-29T11:26:50.264Z|00002|dpdk(pmd-c36/id:6)|INFO|PMD thread released DPDK lcore 1.
2025-01-29T11:26:50.264Z|00158|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 34 destroyed.
2025-01-29T11:26:50.264Z|00002|dpdk(pmd-c34/id:4)|INFO|PMD thread released DPDK lcore 0.
2025-01-29T11:26:55.631Z|00001|vlog|INFO|opened log file /var/log/openvswitch/ovs-vswitchd.log
2025-01-29T11:26:55.634Z|00002|ovs_numa|INFO|Discovered 20 CPU cores on NUMA node 1
2025-01-29T11:26:55.634Z|00003|ovs_numa|INFO|Discovered 20 CPU cores on NUMA node 0
2025-01-29T11:26:55.634Z|00004|ovs_numa|INFO|Discovered 2 NUMA nodes and 40 CPU cores
2025-01-29T11:26:55.634Z|00005|reconnect|INFO|unix:/var/run/openvswitch/db.sock: connecting...
2025-01-29T11:26:55.635Z|00006|reconnect|INFO|unix:/var/run/openvswitch/db.sock: connected
2025-01-29T11:26:55.636Z|00007|dpdk|INFO|DPDK Disabled - Use other_config:dpdk-init to enable
2025-01-29T11:26:55.639Z|00008|bridge|INFO|ovs-vswitchd (Open vSwitch) 3.5.0-0.9.el9fdp
2025-01-29T11:27:03.816Z|00009|dpdk|INFO|Using DPDK 24.11.1
2025-01-29T11:27:03.816Z|00010|dpdk|INFO|DPDK Enabled - initializing...
2025-01-29T11:27:03.816Z|00011|dpdk|INFO|EAL ARGS: ovs-vswitchd --socket-mem 4096 --in-memory -l 0.
2025-01-29T11:27:03.820Z|00012|dpdk|INFO|EAL: Detected CPU lcores: 40
2025-01-29T11:27:03.820Z|00013|dpdk|INFO|EAL: Detected NUMA nodes: 2
2025-01-29T11:27:03.821Z|00014|dpdk|INFO|EAL: Detected static linkage of DPDK
2025-01-29T11:27:03.842Z|00015|dpdk|INFO|EAL: rte_mem_virt2phy(): cannot open /proc/self/pagemap: Permission denied
2025-01-29T11:27:03.842Z|00016|dpdk|INFO|EAL: Selected IOVA mode 'VA'
2025-01-29T11:27:03.842Z|00017|dpdk|WARN|EAL: No free 2048 kB hugepages reported on node 0
2025-01-29T11:27:03.842Z|00018|dpdk|WARN|EAL: No free 2048 kB hugepages reported on node 1
2025-01-29T11:27:03.842Z|00019|dpdk|INFO|EAL: VFIO support initialized
2025-01-29T11:27:04.714Z|00020|dpdk|INFO|EAL: Using IOMMU type 1 (Type 1)
2025-01-29T11:27:05.317Z|00021|netdev_dpdk|INFO|Per port memory for DPDK devices disabled.
2025-01-29T11:27:05.317Z|00022|netdev_dpdk|INFO|No vhost-sock-dir provided - defaulting to /var/run/openvswitch
2025-01-29T11:27:05.317Z|00023|netdev_dpdk|INFO|IOMMU support for vhost-user-client enabled.
2025-01-29T11:27:05.317Z|00024|netdev_dpdk|INFO|POSTCOPY support for vhost-user-client disabled.
2025-01-29T11:27:05.318Z|00025|dpdk|INFO|DPDK Enabled - initialized
2025-01-29T11:27:05.318Z|00026|timeval|WARN|Unreasonably long 1502ms poll interval (11ms user, 819ms system)
2025-01-29T11:27:05.318Z|00027|timeval|WARN|faults: 2314 minor, 0 major
2025-01-29T11:27:05.318Z|00028|timeval|WARN|context switches: 1003 voluntary, 887 involuntary
2025-01-29T11:27:05.319Z|00029|coverage|INFO|Event coverage, avg rate over last: 5 seconds, last minute, last hour,  hash=d3dc6e3a:
2025-01-29T11:27:05.319Z|00030|coverage|INFO|route_table_dump           0.2/sec     0.017/sec        0.0003/sec   total: 1
2025-01-29T11:27:05.319Z|00031|coverage|INFO|netlink_sent               9.2/sec     0.767/sec        0.0128/sec   total: 46
2025-01-29T11:27:05.319Z|00032|coverage|INFO|netlink_recv_jumbo         0.4/sec     0.033/sec        0.0006/sec   total: 2
2025-01-29T11:27:05.319Z|00033|coverage|INFO|netlink_received          10.0/sec     0.833/sec        0.0139/sec   total: 50
2025-01-29T11:27:05.319Z|00034|coverage|INFO|util_xalloc              1766.4/sec   147.200/sec        2.4533/sec   total: 9881
2025-01-29T11:27:05.319Z|00035|coverage|INFO|stream_open                0.2/sec     0.017/sec        0.0003/sec   total: 1
2025-01-29T11:27:05.319Z|00036|coverage|INFO|pstream_open               0.2/sec     0.017/sec        0.0003/sec   total: 1
2025-01-29T11:27:05.319Z|00037|coverage|INFO|seq_change                12.0/sec     1.000/sec        0.0167/sec   total: 65
2025-01-29T11:27:05.319Z|00038|coverage|INFO|poll_create_node          20.2/sec     1.683/sec        0.0281/sec   total: 228
2025-01-29T11:27:05.319Z|00039|coverage|INFO|txn_success                0.4/sec     0.033/sec        0.0006/sec   total: 2
2025-01-29T11:27:05.319Z|00040|coverage|INFO|txn_incomplete             0.6/sec     0.050/sec        0.0008/sec   total: 6
2025-01-29T11:27:05.319Z|00041|coverage|INFO|txn_unchanged              0.6/sec     0.050/sec        0.0008/sec   total: 4
2025-01-29T11:27:05.319Z|00042|coverage|INFO|hmap_expand              103.8/sec     8.650/sec        0.1442/sec   total: 596
2025-01-29T11:27:05.319Z|00043|coverage|INFO|hmap_pathological          1.2/sec     0.100/sec        0.0017/sec   total: 6
2025-01-29T11:27:05.319Z|00044|coverage|INFO|miniflow_malloc            2.8/sec     0.233/sec        0.0039/sec   total: 14
2025-01-29T11:27:05.319Z|00045|coverage|INFO|cmap_expand                2.2/sec     0.183/sec        0.0031/sec   total: 12
2025-01-29T11:27:05.319Z|00046|coverage|INFO|bridge_reconfigure         0.4/sec     0.033/sec        0.0006/sec   total: 4
2025-01-29T11:27:05.319Z|00047|coverage|INFO|150 events never hit
2025-01-29T11:27:46.297Z|00048|memory|INFO|27988 kB peak resident set size after 50.7 seconds
2025-01-29T11:27:46.297Z|00049|memory|INFO|idl-cells-Open_vSwitch:17
2025-01-29T11:27:46.297Z|00050|pmd_perf|INFO|DPDK provided TSC frequency: 2294600 KHz
2025-01-29T11:27:46.297Z|00051|dpif_netdev_extract|INFO|Default MFEX Extract implementation is scalar.
2025-01-29T11:27:46.297Z|00052|dpif_netdev_impl|INFO|Default DPIF implementation is dpif_scalar.
2025-01-29T11:27:46.310Z|00053|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports recirculation
2025-01-29T11:27:46.310Z|00054|ofproto_dpif|INFO|netdev@ovs-netdev: VLAN header stack length probed as 1
2025-01-29T11:27:46.310Z|00055|ofproto_dpif|INFO|netdev@ovs-netdev: MPLS label stack length probed as 3
2025-01-29T11:27:46.310Z|00056|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports truncate action
2025-01-29T11:27:46.310Z|00057|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports unique flow ids
2025-01-29T11:27:46.311Z|00058|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports clone action
2025-01-29T11:27:46.311Z|00059|ofproto_dpif|INFO|netdev@ovs-netdev: Max sample nesting level probed as 10
2025-01-29T11:27:46.311Z|00060|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports eventmask in conntrack action
2025-01-29T11:27:46.311Z|00061|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_clear action
2025-01-29T11:27:46.311Z|00062|ofproto_dpif|INFO|netdev@ovs-netdev: Max dp_hash algorithm probed to be 1
2025-01-29T11:27:46.311Z|00063|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports check_pkt_len action
2025-01-29T11:27:46.311Z|00064|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports timeout policy in conntrack action
2025-01-29T11:27:46.311Z|00065|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports explicit drop action
2025-01-29T11:27:46.311Z|00066|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_zero_snat
2025-01-29T11:27:46.311Z|00067|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports add_mpls action
2025-01-29T11:27:46.311Z|00068|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath does not support psample action
2025-01-29T11:27:46.311Z|00069|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_state
2025-01-29T11:27:46.311Z|00070|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_zone
2025-01-29T11:27:46.311Z|00071|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_mark
2025-01-29T11:27:46.311Z|00072|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_label
2025-01-29T11:27:46.311Z|00073|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_state_nat
2025-01-29T11:27:46.311Z|00074|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_orig_tuple
2025-01-29T11:27:46.311Z|00075|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports ct_orig_tuple6
2025-01-29T11:27:46.311Z|00076|ofproto_dpif|INFO|netdev@ovs-netdev: Datapath supports IPv6 ND Extensions
2025-01-29T11:27:46.311Z|00077|ofproto_dpif_upcall|INFO|Overriding n-handler-threads to 0, setting n-revalidator-threads to 1
2025-01-29T11:27:46.311Z|00078|ofproto_dpif_upcall|INFO|Starting 1 threads
2025-01-29T11:27:46.314Z|00079|dpif_netdev|INFO|pmd-rxq-affinity isolates PMD core
2025-01-29T11:27:46.314Z|00080|dpif_netdev|INFO|PMD auto load balance interval set to 1 mins
2025-01-29T11:27:46.314Z|00081|dpif_netdev|INFO|PMD auto load balance improvement threshold set to 25%
2025-01-29T11:27:46.314Z|00082|dpif_netdev|INFO|PMD auto load balance load threshold set to 95%
2025-01-29T11:27:46.314Z|00083|dpif_netdev|INFO|PMD auto load balance is disabled.
2025-01-29T11:27:46.314Z|00084|dpif_netdev|INFO|Default PMD thread max sleep:    0 us.
2025-01-29T11:27:46.321Z|00085|bridge|INFO|bridge ovsbr2: added interface ovsbr2 on port 65534
2025-01-29T11:27:46.321Z|00086|bridge|INFO|bridge ovsbr2: using datapath ID 00003618a4451d45
2025-01-29T11:27:46.321Z|00087|connmgr|INFO|ovsbr2: added service controller "punix:/var/run/openvswitch/ovsbr2.mgmt"
2025-01-29T11:27:46.332Z|00088|dpif_netdev|INFO|PMD thread on numa_id: 1, core id: 21, max sleep:    0 us.
2025-01-29T11:27:46.332Z|00089|dpif_netdev|INFO|PMD thread on numa_id: 1, core id: 21 created.
2025-01-29T11:27:46.332Z|00090|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 38, max sleep:    0 us.
2025-01-29T11:27:46.332Z|00091|dpif_netdev|INFO|PMD thread on numa_id: 0, core id: 38 created.
2025-01-29T11:27:46.332Z|00092|dpif_netdev|INFO|There are 1 pmd threads on numa node 1
2025-01-29T11:27:46.332Z|00093|dpif_netdev|INFO|There are 1 pmd threads on numa node 0
2025-01-29T11:27:46.332Z|00094|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) Linear buffers requested without external buffers,
2025-01-29T11:27:46.333Z|00095|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) disabling host segmentation offloading support
2025-01-29T11:27:46.333Z|00001|dpdk(pmd-c21/id:7)|INFO|PMD thread uses DPDK lcore 1.
2025-01-29T11:27:46.334Z|00001|dpdk(pmd-c38/id:8)|INFO|PMD thread uses DPDK lcore 2.
2025-01-29T11:27:46.335Z|00096|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vhost-user client: socket created, fd: 62
2025-01-29T11:27:46.335Z|00097|netdev_dpdk|INFO|vHost User device 'vhost0' created in 'client' mode, using client socket '/tmp/vhost0'
2025-01-29T11:27:46.346Z|00098|dpdk|WARN|VHOST_CONFIG: (/tmp/vhost0) failed to connect: No such file or directory
2025-01-29T11:27:46.346Z|00099|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) reconnecting...
2025-01-29T11:27:46.346Z|00100|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:27:46.346Z|00101|dpif_netdev|INFO|Core 38 on numa node 0 assigned port 'vhost0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:27:46.368Z|00102|bridge|INFO|bridge ovsbr2: added interface vhost0 on port 1
2025-01-29T11:27:53.335Z|00001|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) connected
2025-01-29T11:27:53.335Z|00002|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) new device, handle is 0
2025-01-29T11:27:53.367Z|00001|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_FEATURES
2025-01-29T11:27:53.367Z|00002|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_PROTOCOL_FEATURES
2025-01-29T11:27:53.367Z|00003|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_PROTOCOL_FEATURES
2025-01-29T11:27:53.367Z|00004|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) negotiated Vhost-user protocol features: 0x10cbf
2025-01-29T11:27:53.367Z|00005|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_QUEUE_NUM
2025-01-29T11:27:53.367Z|00006|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_BACKEND_REQ_FD
2025-01-29T11:27:53.367Z|00007|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_OWNER
2025-01-29T11:27:53.367Z|00008|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_FEATURES
2025-01-29T11:27:53.367Z|00009|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_CALL
2025-01-29T11:27:53.367Z|00010|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring call idx:0 file:67
2025-01-29T11:27:53.367Z|00011|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ERR
2025-01-29T11:27:53.367Z|00012|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_CALL
2025-01-29T11:27:53.367Z|00013|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring call idx:1 file:68
2025-01-29T11:27:53.367Z|00014|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ERR
2025-01-29T11:27:56.369Z|00103|memory|INFO|peak resident set size grew 110% in last 10.1 seconds, from 27988 kB to 58708 kB
2025-01-29T11:27:56.369Z|00104|memory|INFO|idl-cells-Open_vSwitch:153 ports:2 revalidators:1 rules:5
2025-01-29T11:28:06.009Z|00015|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.009Z|00016|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 0
2025-01-29T11:28:06.009Z|00017|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.009Z|00018|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 1
2025-01-29T11:28:06.009Z|00019|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.009Z|00020|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 0
2025-01-29T11:28:06.009Z|00021|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.009Z|00022|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 1
2025-01-29T11:28:06.260Z|00023|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.260Z|00024|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 0
2025-01-29T11:28:06.260Z|00025|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ENABLE
2025-01-29T11:28:06.260Z|00026|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) set queue enable: 1 to qp idx: 1
2025-01-29T11:28:06.276Z|00027|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_FEATURES
2025-01-29T11:28:06.276Z|00028|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) negotiated Virtio features: 0x170202783
2025-01-29T11:28:06.276Z|00029|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_STATUS
2025-01-29T11:28:06.276Z|00030|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_STATUS
2025-01-29T11:28:06.276Z|00031|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) new device status(0x00000008):
2025-01-29T11:28:06.276Z|00032|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -RESET: 0
2025-01-29T11:28:06.276Z|00033|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -ACKNOWLEDGE: 0
2025-01-29T11:28:06.276Z|00034|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER: 0
2025-01-29T11:28:06.276Z|00035|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FEATURES_OK: 1
2025-01-29T11:28:06.276Z|00036|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER_OK: 0
2025-01-29T11:28:06.276Z|00037|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DEVICE_NEED_RESET: 0
2025-01-29T11:28:06.276Z|00038|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FAILED: 0
2025-01-29T11:28:06.276Z|00039|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_MEM_TABLE
2025-01-29T11:28:06.276Z|00040|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) guest memory region size: 0x80000000
2025-01-29T11:28:06.276Z|00041|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      guest physical addr: 0x0
2025-01-29T11:28:06.276Z|00042|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      guest virtual  addr: 0x7eff80000000
2025-01-29T11:28:06.276Z|00043|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      host  virtual  addr: 0x7fc2c0000000
2025-01-29T11:28:06.276Z|00044|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap addr : 0x7fc2c0000000
2025-01-29T11:28:06.276Z|00045|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap size : 0x80000000
2025-01-29T11:28:06.276Z|00046|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap align: 0x40000000
2025-01-29T11:28:06.276Z|00047|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap off  : 0x0
2025-01-29T11:28:06.276Z|00048|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) guest memory region size: 0x180000000
2025-01-29T11:28:06.276Z|00049|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      guest physical addr: 0x100000000
2025-01-29T11:28:06.276Z|00050|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      guest virtual  addr: 0x7f0000000000
2025-01-29T11:28:06.276Z|00051|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      host  virtual  addr: 0x7fc140000000
2025-01-29T11:28:06.276Z|00052|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap addr : 0x7fc0c0000000
2025-01-29T11:28:06.276Z|00053|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap size : 0x200000000
2025-01-29T11:28:06.276Z|00054|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap align: 0x40000000
2025-01-29T11:28:06.276Z|00055|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)      mmap off  : 0x80000000
2025-01-29T11:28:06.276Z|00056|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_NUM
2025-01-29T11:28:06.276Z|00057|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_BASE
2025-01-29T11:28:06.276Z|00058|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring base idx:0 last_used_idx:0 last_avail_idx:0.
2025-01-29T11:28:06.276Z|00059|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ADDR
2025-01-29T11:28:06.276Z|00060|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_KICK
2025-01-29T11:28:06.276Z|00061|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring kick idx:0 file:71
2025-01-29T11:28:06.276Z|00062|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_CALL
2025-01-29T11:28:06.276Z|00063|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring call idx:0 file:72
2025-01-29T11:28:06.276Z|00064|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_NUM
2025-01-29T11:28:06.276Z|00065|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_BASE
2025-01-29T11:28:06.276Z|00066|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring base idx:1 last_used_idx:0 last_avail_idx:0.
2025-01-29T11:28:06.276Z|00067|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_ADDR
2025-01-29T11:28:06.276Z|00068|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_KICK
2025-01-29T11:28:06.276Z|00069|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring kick idx:1 file:67
2025-01-29T11:28:06.276Z|00070|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_VRING_CALL
2025-01-29T11:28:06.276Z|00071|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring call idx:1 file:73
2025-01-29T11:28:06.276Z|00072|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_STATUS
2025-01-29T11:28:06.276Z|00073|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_STATUS
2025-01-29T11:28:06.276Z|00074|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) new device status(0x0000000f):
2025-01-29T11:28:06.276Z|00075|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -RESET: 0
2025-01-29T11:28:06.276Z|00076|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -ACKNOWLEDGE: 1
2025-01-29T11:28:06.276Z|00077|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER: 1
2025-01-29T11:28:06.276Z|00078|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FEATURES_OK: 1
2025-01-29T11:28:06.276Z|00079|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER_OK: 1
2025-01-29T11:28:06.276Z|00080|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DEVICE_NEED_RESET: 0
2025-01-29T11:28:06.276Z|00081|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FAILED: 0
2025-01-29T11:28:06.276Z|00082|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) virtio is now ready for processing.
2025-01-29T11:28:06.276Z|00083|netdev_dpdk|INFO|vHost Device '/tmp/vhost0' has been added on numa node 0
2025-01-29T11:28:06.343Z|00001|netdev_dpdk(ovs_vhost2)|INFO|State of queue 0 ( tx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'enabled'
2025-01-29T11:28:06.343Z|00002|netdev_dpdk(ovs_vhost2)|INFO|State of queue 0 ( tx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'disabled'
2025-01-29T11:28:06.343Z|00003|netdev_dpdk(ovs_vhost2)|INFO|State of queue 0 ( tx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'enabled'
2025-01-29T11:28:06.343Z|00004|netdev_dpdk(ovs_vhost2)|INFO|State of queue 1 ( rx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'enabled'
2025-01-29T11:28:06.343Z|00005|netdev_dpdk(ovs_vhost2)|INFO|State of queue 1 ( rx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'disabled'
2025-01-29T11:28:06.343Z|00006|netdev_dpdk(ovs_vhost2)|INFO|State of queue 1 ( rx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'enabled'
2025-01-29T11:28:06.343Z|00105|dpif_netdev|INFO|Performing pmd to rx queue assignment using cycles algorithm.
2025-01-29T11:28:06.343Z|00106|dpif_netdev|INFO|Core 38 on numa node 0 assigned port 'vhost0' rx queue 0 (measured processing cycles 0).
2025-01-29T11:28:08.077Z|00084|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_VRING_BASE
2025-01-29T11:28:08.077Z|00085|netdev_dpdk|INFO|vHost Device '/tmp/vhost0' has been removed
2025-01-29T11:28:08.077Z|00086|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring base idx:0 file:0
2025-01-29T11:28:08.078Z|00087|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_GET_VRING_BASE
2025-01-29T11:28:08.078Z|00088|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vring base idx:1 file:0
2025-01-29T11:28:08.078Z|00089|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) read message VHOST_USER_SET_STATUS
2025-01-29T11:28:08.078Z|00090|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) new device status(0x00000000):
2025-01-29T11:28:08.078Z|00091|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -RESET: 1
2025-01-29T11:28:08.078Z|00092|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -ACKNOWLEDGE: 0
2025-01-29T11:28:08.078Z|00093|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER: 0
2025-01-29T11:28:08.078Z|00094|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FEATURES_OK: 0
2025-01-29T11:28:08.078Z|00095|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DRIVER_OK: 0
2025-01-29T11:28:08.078Z|00096|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -DEVICE_NEED_RESET: 0
2025-01-29T11:28:08.078Z|00097|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0)     -FAILED: 0
2025-01-29T11:28:08.136Z|00007|netdev_dpdk(ovs_vhost2)|INFO|State of queue 0 ( tx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'disabled'
2025-01-29T11:28:08.136Z|00008|netdev_dpdk(ovs_vhost2)|INFO|State of queue 1 ( rx_qid 0 ) of vhost device '/tmp/vhost0' changed to 'disabled'
2025-01-29T11:28:47.436Z|00098|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vhost peer closed
2025-01-29T11:28:47.436Z|00099|netdev_dpdk|INFO|vHost Device '/tmp/vhost0' connection has been destroyed
2025-01-29T11:28:47.436Z|00100|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) vhost-user client: socket created, fd: 62
2025-01-29T11:28:47.436Z|00101|dpdk|WARN|VHOST_CONFIG: (/tmp/vhost0) failed to connect: No such file or directory
2025-01-29T11:28:47.436Z|00102|dpdk|INFO|VHOST_CONFIG: (/tmp/vhost0) reconnecting...
2025-01-29T11:28:47.436Z|00103|dpdk|ERR|VHOST_FDMAN: could not remove 62 fd from 63 epfd: No such file or directory

              mcoqueli@redhat.com Maxime Coquelin
              mhou@redhat.com Minxi Hou
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Created:
                Updated: