Created attachment 1598810 [details] ovs-vswitchd.log Description of problem: FDP 19.E: openvswitch service fails to start with DPDK config and driverctl override list is empty. Version-Release number of selected component (if applicable): RHEL 7.7 (kernel 3.10.0-1062.el7.x86_64) OVS: openvswitch2.11-2.11.0-18.el7fdp.x86_64 DPDK: 1811-2 driverctl: driverctl-0.110-1.el7.noarch How reproducible: Always Steps to Reproduce: 1. Configure DPDK with driverctl overrides 2. systemctl stop openvswitch 3. driverctl unset-override <pci slot> for both pci slots 4. systemctl start openvswitch Actual results: openvswitch.service fails to start Expected results: openvswitch.service starts Additional info: Steps to configure and test: RPM_CONTAINER_SELINUX_POLICY="http://download-node-02.eng.bos.redhat.com/brewroot/packages/container-selinux/2.77/1.el7_6/noarch/container-selinux-2.77-1.el7_6.noarch.rpm" RPM_OVS_SELINUX_EXTRA_POLICY="http://download-node-02.eng.bos.redhat.com/brewroot/packages/openvswitch-selinux-extra-policy/1.0/13.el7fdp/noarch/openvswitch-selinux-extra-policy-1.0-13.el7fdp.noarch.rpm" # 2.11 RPM_OVS="http://download-node-02.eng.bos.redhat.com/brewroot/packages/openvswitch2.11/2.11.0/18.el7fdp/x86_64/openvswitch2.11-2.11.0-18.el7fdp.x86_64.rpm" iface1="p3p1" iface2="p3p2" dpdk_iface1=${dpdk_iface1:-"p3p1"} dpdk_iface2=${dpdk_iface2:-"p3p2"} use_dpdk=${use_dpdk:-"yes"} ovsbr="ovsbr0" if [[ ! -s /home/dpdk_pci_slot1.txt ]]; then ethtool -i "$dpdk_iface1" | grep "bus-info" | awk '{print $2}' > /home/dpdk_pci_slot1.txt fi if [[ ! -s /home/dpdk_pci_slot2.txt ]]; then ethtool -i "$dpdk_iface2" | grep "bus-info" | awk '{print $2}' > /home/dpdk_pci_slot2.txt fi dpdk_pci_slot1=$(cat /home/dpdk_pci_slot1.txt) dpdk_pci_slot2=$(cat /home/dpdk_pci_slot2.txt) pvt_driverctl_install() { driverctl_rpm=${driverctl_rpm:-"http://download-node-02.eng.bos.redhat.com/brewroot/packages/driverctl/0.110/1.el7/noarch/driverctl-0.110-1.el7.noarch.rpm"} if rpm -q driverctl 2>/dev/null; then echo "driverctl is already installed" return 0 else echo "Installing driverctl..." yum -y install $driverctl_rpm fi } pvt_tuned_install() { # install latest tuned packages on host rhel_version=$(cut -f1 -d. /etc/redhat-release | sed 's/[^0-9]//g') SERVER="download-node-02.eng.bos.redhat.com" if [ $rhel_version -eq 7 ]; then latest_tuned_major_ver="2.11.0" elif [ $rhel_version -eq 8 ]; then latest_tuned_major_ver="2.12.0" fi latest_tuned_minor_ver=$(curl -sL http://download-node-02.eng.bos.redhat.com/brewroot/packages/tuned/$latest_tuned_major_ver | grep DIR | egrep -v 'brew|pub|guest' | tail -n1 | awk '{print $5}' | awk -F '"' '{print $2}' | tr -d /) tuned_rpm="tuned-$latest_tuned_major_ver-$latest_tuned_minor_ver.noarch.rpm" yum -y install python-linux-procfs python-schedutils tuna rpm -ivh http://$SERVER/brewroot/packages/tuned/$latest_tuned_major_ver/$latest_tuned_minor_ver/noarch/$tuned_rpm if [[ $? -ne 0 ]] && [[ $(rpm -q tuned) ]]; then rpm -e tuned rpm -ivh http://$SERVER/brewroot/packages/tuned/$latest_tuned_major_ver/$latest_tuned_minor_ver/noarch/$tuned_rpm fi rpm -ivh http://$SERVER/brewroot/packages/tuned/$latest_tuned_major_ver/$latest_tuned_minor_ver/noarch/tuned-profiles-cpu-partitioning-$latest_tuned_major_ver-$latest_tuned_minor_ver.noarch.rpm systemctl enable tuned && systemctl start tuned } configure_hugepages() { $dbg_flag # configure hugepages on the host sed -i -e 's/GRUB_CMDLINE_LINUX="/GRUB_CMDLINE_LINUX="default_hugepagesz=1G hugepagesz=1G hugepages=32 iommu=pt intel_iommu=on/' /etc/default/grub grub2-editenv - unset kernelopts grub2-mkconfig -o /boot/grub2/grub.cfg } tune_host() { $dbg_flag lscpu |grep -E "^CPU\(s\)|On-line|Thread\(s\) per core" yum -y install tuned yum -y install tuned-profiles-cpu-partitioning systemctl enable tuned systemctl start tuned NIC1="$iface1" NIC2="$iface2" NIC1_PCI_ADDR=$(ethtool -i $NIC1 | grep -Eo '[0-9]+:[0-9]+:[0-9]+\.[0-9]+') NIC2_PCI_ADDR=$(ethtool -i $NIC2 | grep -Eo '[0-9]+:[0-9]+:[0-9]+\.[0-9]+') NICNUMA=$(cat /sys/class/net/$NIC1/device/numa_node) ISOLCPUS=$(lscpu | grep "NUMA node$NICNUMA" | awk '{print $4}') if [ $(echo $ISOLCPUS | awk /'^0,'/) ]; then ISOLCPUS=$(echo $ISOLCPUS | cut -c 3-) fi echo -e "isolated_cores=$ISOLCPUS" >> /etc/tuned/cpu-partitioning-variables.conf tuned-adm profile cpu-partitioning } dpdk_config() { $dbg_flag echo "$dpdk_iface1 PCI slot: $dpdk_pci_slot1" echo "$dpdk_iface2 PCI slot: $dpdk_pci_slot2" dpdk_pci_slot_list="$dpdk_pci_slot1 $dpdk_pci_slot2" systemctl stop openvswitch.service for i in $dpdk_pci_slot_list; do driverctl -v list-overrides | grep $i if [[ $? -eq 0 ]]; then driverctl -v unset-override $i fi driverctl -v set-override $i vfio-pci driverctl -v list-overrides | grep $i if [[ $? -eq 0 ]]; then echo "Driver override successfully set for PCI slot $i" else echo "Driver override FAILED for PCI slot $i. Exiting test..." fi done systemctl start openvswitch ovs-vsctl set Open_vSwitch . other_config={} ovs-vsctl --no-wait set Open_vSwitch . other_config:dpdk-init=true ovs-vsctl --no-wait set Open_vSwitch . other_config:dpdk-lcore-mask=0x000002 ovs-vsctl --no-wait set Open_vSwitch . other_config:dpdk-socket-mem="4096,1" sleep 5 systemctl restart openvswitch sleep 5 ovs-vsctl --if-exists del-br $ovsbr ovs-vsctl set Open_vSwitch . other_config:pmd-cpu-mask=0xaa00 ovs-vsctl add-br $ovsbr -- set bridge $ovsbr datapath_type=netdev ovs-vsctl add-port $ovsbr dpdk-1005 -- set interface dpdk-1005 type=dpdk ofport_request=1005 options:dpdk-devargs=$dpdk_pci_slot1 ovs-vsctl add-port $ovsbr dpdk-1010 -- set interface dpdk-1010 type=dpdk ofport_request=1010 options:dpdk-devargs=$dpdk_pci_slot2 ovs-vsctl add-port $ovsbr vhost0 -- set interface vhost0 type=dpdkvhostuserclient options:vhost-server-path=/tmp/vhost0 ofport_request=1015 ovs-vsctl add-port $ovsbr vhost1 -- set interface vhost1 type=dpdkvhostuserclient options:vhost-server-path=/tmp/vhost1 ofport_request=1020 vhost_file_list="/tmp/vhost0 /tmp/vhost1 /var/run/openvswitch/vhost0 /var/run/openvswitch/vhost1" for vhost_file in $vhost_file_list; do #touch $vhost_file if [[ -e $vhost_file ]]; then chmod 777 $vhost_file sleep 3 ls -alt $vhost_file fi done chmod 777 /tmp && sleep 3 && ls -ald /tmp ovs-vsctl show } # Steps: pvt_driverctl_install pvt_tuned_install configure_hugepages tune_host reboot # After system comes back up: yum -y install $RPM_CONTAINER_SELINUX_POLICY yum -y install $RPM_OVS_SELINUX_EXTRA_POLICY yum -y install $RPM_OVS dpdk_config [root@netqe5 ~]# driverctl list-overrides 0000:83:00.0 vfio-pci 0000:83:00.1 vfio-pci systemctl restart openvswitch systemctl stop openvswitch driverctl unset-override 0000:83:00.0 driverctl unset-override 0000:83:00.1 driverctl list-overrides systemctl start openvswitch # service fails to come up ####################################################### To test repeatedly: [root@netqe6 ~]# cat test.sh while [ 1 ]; do echo "Stopping openvswitch.service..." systemctl stop openvswitch sleep 1 echo "Checking status of openvswitch.service..." echo "openvswitch.service status is: $(systemctl is-active openvswitch)" sleep 1 echo "Setting driverctl overrides..." driverctl -v set-override 0000:83:00.0 vfio-pci sleep 1 driverctl -v set-override 0000:83:00.1 vfio-pci sleep 1 echo "Listing driverctl overrides..." driverctl list-overrides sleep 1 echo "Starting openvswitch.service..." systemctl start openvswitch sleep 1 echo "Checking status of openvswitch.service..." echo "openvswitch.service status is: $(systemctl is-active openvswitch)" sleep 1 echo "Stopping openvswitch.service..." systemctl stop openvswitch sleep 1 echo "Checking status of openvswitch.service..." echo "openvswitch.service status is: $(systemctl is-active openvswitch)" sleep 1 echo "Unsetting driverctl overrides..." driverctl -v unset-override 0000:83:00.0 sleep 1 driverctl -v unset-override 0000:83:00.1 sleep 1 echo "Listing driverctl overrides..." driverctl list-overrides sleep 1 echo "Checking status of openvswitch.service..." echo "openvswitch.service status is: $(systemctl is-active openvswitch)" sleep 1 echo "Starting openvswitch.service..." systemctl start openvswitch sleep 1 echo "Checking status of openvswitch.service..." echo "openvswitch.service status is: $(systemctl is-active openvswitch)" done ####################################################### Notes: This issue does not occur when running RHEL 7.6 (kernel 3.10.0-957.27.2.el7.x86_64) with either openvswitch-2.9.0-114.el7fdp.x86_64 or openvswitch2.11-2.11.0-18.el7fdp. It does occur with RHEL 7.7 (kernel 3.10.0-1062.el7.x86_64) and openvswitch2.11-2.11.0-18.el7fdp. openvswitch logs attached. sosreport: http://netqe-infra01.knqe.lab.eng.bos.redhat.com/sosreports/sosreport-netqe6-2019-08-01-xrgohxc.tar.xz
Created attachment 1598818 [details] ovsdb-server.log
I can't seem to access the ovs-vswitchd.log from the sosreport - can you attach it also? And the journalctl -u openvswitch, journalctl -u ovsdb-server, journalctl -u ovs-vswitchd output, if possible.
Actually, I see this from the error logs: 2019-08-01T18:07:09.590Z|00020|dpdk|EMER|Unable to initialize DPDK: Cannot allocate memory Can you get the output of /proc/meminfo ? You can also systemctl start ovsdb-server ovs-vsctl --no-wait get Open_vSwitch . other_config
ovs-vswitchd.log and ovsdb-server.log are attached to this BZ. I forgot to include this output: [root@netqe6 ~]# ovs-vsctl list Open_vSwitch _uuid : fa94b582-af81-4d68-834f-a937930eb330 bridges : [636054cd-0db1-4990-815c-d008234d6529] cur_cfg : 6 datapath_types : [netdev, system] db_version : "7.16.1" dpdk_initialized : true dpdk_version : "DPDK 18.11.2" external_ids : {hostname="netqe6.knqe.lab.eng.bos.redhat.com", rundir="/var/run/openvswitch", system-id="48a99a25-51d6-474d-8b77-766541b6b8a3"} iface_types : [dpdk, dpdkr, dpdkvhostuser, dpdkvhostuserclient, erspan, geneve, gre, internal, "ip6erspan", "ip6gre", lisp, patch, stt, system, tap, vxlan] manager_options : [] next_cfg : 6 other_config : {dpdk-init="true", dpdk-lcore-mask="0x000002", dpdk-socket-mem="4096,1", pmd-cpu-mask="0xaa00"} ovs_version : "2.11.0" ssl : [] statistics : {} system_type : rhel system_version : "7.7" Info requested: [root@netqe6 ~]# cat /proc/meminfo MemTotal: 65772872 kB MemFree: 30824936 kB MemAvailable: 30830116 kB Buffers: 2540 kB Cached: 368148 kB SwapCached: 0 kB Active: 304156 kB Inactive: 137724 kB Active(anon): 78368 kB Inactive(anon): 11036 kB Active(file): 225788 kB Inactive(file): 126688 kB Unevictable: 0 kB Mlocked: 0 kB SwapTotal: 32964604 kB SwapFree: 32964604 kB Dirty: 0 kB Writeback: 0 kB AnonPages: 71196 kB Mapped: 34372 kB Shmem: 18212 kB Slab: 159312 kB SReclaimable: 74336 kB SUnreclaim: 84976 kB KernelStack: 5104 kB PageTables: 4312 kB NFS_Unstable: 0 kB Bounce: 0 kB WritebackTmp: 0 kB CommitLimit: 49073824 kB Committed_AS: 307876 kB VmallocTotal: 34359738367 kB VmallocUsed: 436008 kB VmallocChunk: 34325399548 kB HardwareCorrupted: 0 kB AnonHugePages: 6144 kB CmaTotal: 0 kB CmaFree: 0 kB HugePages_Total: 32 HugePages_Free: 32 HugePages_Rsvd: 0 HugePages_Surp: 0 Hugepagesize: 1048576 kB DirectMap4k: 249552 kB DirectMap2M: 5943296 kB DirectMap1G: 62914560 kB [root@netqe6 ~]# systemctl start ovsdb-server [root@netqe6 ~]# ovs-vsctl --no-wait get Open_vSwitch . other_config {dpdk-init="true", dpdk-lcore-mask="0x000002", dpdk-socket-mem="4096,1", pmd-cpu-mask="0xaa00"} Attaching journalctl output requested.
Created attachment 1599041 [details] journalctl.info
Based on my investigation this is a 2.11 specific issue. And, it could be a dup of bug 1672849.
Using the same reproducer with OVS 2.9.0-114 got only one ERR. And, DPDK got initialized successfully, and OVS started successfully. 2019-08-01T20:38:14.053Z|00013|dpdk|INFO|EAL: Probing VFIO support... 2019-08-01T20:38:14.053Z|00014|dpdk|INFO|EAL: VFIO support initialized 2019-08-01T20:38:14.054Z|00015|dpdk|ERR|EAL: Cannot obtain physical addresses: Permission denied. Only vfio will function. 2019-08-01T20:38:21.683Z|00016|dpdk|INFO|EAL: PCI device 0000:19:00.0 on NUMA socket 0 2019-08-01T20:38:21.683Z|00017|dpdk|INFO|EAL: probe driver: 8086:1521 net_e1000_igb 2019-08-01T20:38:21.683Z|00018|dpdk|INFO|EAL: PCI device 0000:19:00.1 on NUMA socket 0 2019-08-01T20:38:21.683Z|00019|dpdk|INFO|EAL: probe driver: 8086:1521 net_e1000_igb 2019-08-01T20:38:21.683Z|00020|dpdk|INFO|EAL: PCI device 0000:19:00.2 on NUMA socket 0 2019-08-01T20:38:21.683Z|00021|dpdk|INFO|EAL: probe driver: 8086:1521 net_e1000_igb 2019-08-01T20:38:21.683Z|00022|dpdk|INFO|EAL: PCI device 0000:19:00.3 on NUMA socket 0 2019-08-01T20:38:21.683Z|00023|dpdk|INFO|EAL: probe driver: 8086:1521 net_e1000_igb 2019-08-01T20:38:21.683Z|00024|dpdk|INFO|EAL: PCI device 0000:3b:00.0 on NUMA socket 0 2019-08-01T20:38:21.683Z|00025|dpdk|INFO|EAL: probe driver: 15b3:1013 net_mlx5 2019-08-01T20:38:21.684Z|00026|dpdk|INFO|PMD: net_mlx5: PCI information matches, using device "mlx5_0" (SR-IOV: false) 2019-08-01T20:38:21.687Z|00027|dpdk|INFO|PMD: net_mlx5: 1 port(s) detected 2019-08-01T20:38:21.690Z|00028|dpdk|INFO|PMD: net_mlx5: MPS is disabled 2019-08-01T20:38:21.691Z|00029|dpdk|INFO|PMD: net_mlx5: port 1 MAC address is 24:8a:07:87:22:ce 2019-08-01T20:38:21.693Z|00030|dpdk|INFO|EAL: PCI device 0000:3b:00.1 on NUMA socket 0 2019-08-01T20:38:21.693Z|00031|dpdk|INFO|EAL: probe driver: 15b3:1013 net_mlx5 2019-08-01T20:38:21.693Z|00032|dpdk|INFO|PMD: net_mlx5: PCI information matches, using device "mlx5_1" (SR-IOV: false) 2019-08-01T20:38:21.695Z|00033|dpdk|INFO|PMD: net_mlx5: 1 port(s) detected 2019-08-01T20:38:21.698Z|00034|dpdk|INFO|PMD: net_mlx5: MPS is disabled 2019-08-01T20:38:21.698Z|00035|dpdk|INFO|PMD: net_mlx5: port 1 MAC address is 24:8a:07:87:22:cf 2019-08-01T20:38:21.700Z|00036|dpdk|INFO|EAL: PCI device 0000:5e:00.0 on NUMA socket 0 2019-08-01T20:38:21.700Z|00037|dpdk|INFO|EAL: probe driver: 8086:158b net_i40e 2019-08-01T20:38:21.700Z|00038|dpdk|INFO|EAL: PCI device 0000:5e:00.1 on NUMA socket 0 2019-08-01T20:38:21.700Z|00039|dpdk|INFO|EAL: probe driver: 8086:158b net_i40e 2019-08-01T20:38:21.700Z|00040|dpdk|INFO|EAL: PCI device 0000:5f:00.0 on NUMA socket 0 2019-08-01T20:38:21.700Z|00041|dpdk|INFO|EAL: probe driver: 19ee:4000 net_nfp_pf 2019-08-01T20:38:21.701Z|00042|dpdk|INFO|DPDK Enabled - initialized
Additional info: The driver in use for this test is ixgbe. The only other type NIC card/driver in the system under test is bnx2x. [root@netqe6 ~]# ethtool -i p3p1 driver: ixgbe version: 5.1.0-k-rh7.7 firmware-version: 0x80000389 expansion-rom-version: bus-info: 0000:83:00.0 supports-statistics: yes supports-test: yes supports-eeprom-access: yes supports-register-dump: yes supports-priv-flags: yes To reiterate the initial notes for this bugs: This issue does NOT occur when running RHEL 7.6 (kernel 3.10.0-957.27.2.el7.x86_64) with either openvswitch-2.9.0-114.el7fdp.x86_64 or openvswitch2.11-2.11.0-18.el7fdp. It DOES occur with RHEL 7.7 (kernel 3.10.0-1062.el7.x86_64) and openvswitch2.11-2.11.0-18.el7fdp. In the testing I performed, this issue was specific to RHEL 7.7 (kernel 3.10.0-1062.el7.x86_64) and openvswitch2.11-2.11.0-18.el7fdp.
NOTE: Got the same issue even with root as the user: #OVS_USER_ID="openvswitch:hugetlbfs"
This is addressed with bz1711739. *** This bug has been marked as a duplicate of bug 1711739 ***