From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-qk0-f179.google.com (mail-qk0-f179.google.com [209.85.220.179]) by dpdk.org (Postfix) with ESMTP id 580EE5684 for ; Fri, 18 Mar 2016 09:36:23 +0100 (CET) Received: by mail-qk0-f179.google.com with SMTP id o6so46121478qkc.2 for ; Fri, 18 Mar 2016 01:36:23 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=canonical-com.20150623.gappssmtp.com; s=20150623; h=mime-version:from:date:message-id:subject:to; bh=XG6NZaIJ/5lBbXZUAb/tDj57QPpcRxeXlM7vIZzFoDk=; b=Df/vgz+SwChSZD5maRAD1vhfjwqRVegI+TjwivHKKuWQhpZawsFZhetwx/Nb0xqJLJ 8u/Sa/Jh5Lq5VL9PBK1GuSFnR3eHDKiPVwZv/q4gczVrL4pPZRxh6/9zVnAAsXlY1qIa 4oa+uFh3twtD2/ECMb4ZXKEFfxPRgHkIMxzbOuQ7qpazcPQsSLRSYun+1D78YiJ0U+12 NYuR5QE0rIw8wuV+Lu88/eMUo5nR1SCMLeb4hQMeIrv6UC3Aj9MW2TZlvY3F1dbp5Yke gg6oxx0ezOGvvLR4tyDJQsBTQyU4doQEWgZwQSXanBOyXHne46hTKGUUUXppfszHxeu4 FCZg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=XG6NZaIJ/5lBbXZUAb/tDj57QPpcRxeXlM7vIZzFoDk=; b=g5zeXhQeh2hvwfHYGQz0XxIR8dyHwWDbYnGGfMg0T7vhUAVGMhXXRFoJJi4+Ob+X/h UaqWQNSvQesVPRLPT/IVUV8z9/QAYHwAV1w3ynT4r3F7Unl1R0TOL1mYEQVcy35Dphmp gm4kSJhmNY+2rgbRWs+esxzQ72aceklRLrM+ORRL9KiHmpLVQ1g+pvJaH7CeHXqIRuYH Y3tDvUDhbbtse3Z+bP7usrQA7Pccc+kApDY6NATk2kIU3PLAicTlAkS9uNz5D59rsQ2y o/zVVREMfJvwqv+NMI0jciuA/Y8osoGnDAkpSHuQNOR8MQNEnE4S1YZhRsV62YiRaUGY 5Nlg== X-Gm-Message-State: AD7BkJJpneDcNMq0JH6x9eDbs3rZ7pY+pFOAikvLlAMmvSKWBRzCaAiBkzqzjIFMqrB83U53k78lSTqkBG4ysmRC X-Received: by 10.55.197.207 with SMTP id k76mr20526366qkl.15.1458290182695; Fri, 18 Mar 2016 01:36:22 -0700 (PDT) MIME-Version: 1.0 Received: by 10.55.169.6 with HTTP; Fri, 18 Mar 2016 01:36:03 -0700 (PDT) From: Christian Ehrhardt Date: Fri, 18 Mar 2016 09:36:03 +0100 Message-ID: To: dev Content-Type: text/plain; charset=UTF-8 X-Content-Filtered-By: Mailman/MimeDel 2.1.15 Subject: [dpdk-dev] virtio-pci and vdev=eth_pcap combined lead to a hang on virtnet_set_rx_mode (lcore-slave) X-BeenThere: dev@dpdk.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: patches and discussions about DPDK List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 18 Mar 2016 08:36:23 -0000 Hi, TL;DR When using --vdev=eth_pcap0 on testpmd "quit" the guest runs into a blocked cpu on virtnet_set_rx_mode (lcore-slave). Using these devices actually appers to be fine, but on the release path (testpmd quit) the issue triggers. Maybe virtio-pci and vdev=eth_pcap are just incompatible, but then there could be more graceful exits :-) Background: I was "reusing" a testpmd commandline I had used on a physical system on a KVM guest. Doing so caused weird hangs. Unfortunately I didn't have the time to debug it down to a fix, but along the way of checking what actually was going on I collected quite a few logs that I wanted to share. If anybody recognizes (or even debugs and fixes) it right away great, if not it will at least be "google'able" by the next with a similar issue. Steps to reproduce: Failing Commandline: sudo /usr/bin/testpmd --pci-blacklist 0000:00:03.0 --socket-mem 2048 --vdev=eth_pcap0,iface=eth1 --vdev=eth_pcap1,iface=eth2 -- --interactive --total-num-mbufs=2048 Note: Working Commandline is the same just without vdev's sudo /usr/bin/testpmd --pci-blacklist 0000:00:03.0 --socket-mem 2048 -- --interactive --total-num-mbufs=2048 The blacklist on 03.0 is the device that I use to run ssh into the guest. Setup: (The setup of the physical system is equivalent, just ixgbe cards instead of virtio) - DPDK 2.2 / Qemu 2.5 - guest has 3 virtio network devices - one to actually connect to it via ssh - two to be dedicated for dpdk experiments - I kept them at the virtio-pci driver, dpdk_nic_bind status: Network devices using kernel driver =================================== 0000:00:03.0 'Virtio network device' if= drv=virtio-pci unused= 0000:00:04.0 'Virtio network device' if= drv=virtio-pci unused= 0000:00:05.0 'Virtio network device' if= drv=virtio-pci unused= - ~3G hugepages are allocated (in 1536 2M hugepages) - 4 virtual CPUs in the guest - virtio-net devices have 4 queues each, combined with ethtool ethtool -L eth1 current values: tx 0 rx 0 other 0 combined 4 After start testpmd initialization is ok - got into interactive shell of testpmd, all fine - ping Host to guest main dev still ok after testpmd start, protected by blacklist (expected) - ping Host to guest dpdk used dev stops (expected) Nothing else interesting on journal / console of host or guest Checking config from testpmds interactive console also didn't show anything obvious to me. Run "start tx_first" - still all fine; ping to main console and guest ssh connectivity ok. - host saw something happening on one of the dpdk ports, but nothing stopped any active conenction kernel: localbridge0: port 2(vnet1) neighbor 8000.52:54:00:0f:a3:5f lost kernel: localbridge0: topology change detected, propagating But then "quit" in testpmd seems to upset something in the guest >>From the quit itselt I get a hanging: testpmd> quit Stopping port 0...done Stopping port 1...done Stopping port 2...done Stopping port 3...done bye... (hangs here) The guest console at the same time triggers a hang check [ 1712.124021] NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [lcore-slave-1:5653] The guests journal list the soft lockup deatils as: dpdk-guest1 kernel: device eth2 left promiscuous mode dpdk-guest1 kernel: NMI watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [lcore-slave-1:5653] dpdk-guest1 kernel: Modules linked in: xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack xt_tcpudp bridge stp llc iptable_filter ip_tables x_tables isofs ppdev kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul joydev serio_raw parport_pc parport iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear aesni_intel psmouse aes_x86_64 glue_helper lrw gf128mul ablk_helper cryptd floppy dpdk-guest1 kernel: CPU: 1 PID: 5653 Comm: lcore-slave-1 Not tainted 4.4.0-13-generic #29-Ubuntu dpdk-guest1 kernel: Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Ubuntu-1.8.2-1ubuntu1 04/01/2014 dpdk-guest1 kernel: task: ffff8801b7626040 ti: ffff8800ba944000 task.ti: ffff8800ba944000 dpdk-guest1 kernel: RIP: 0010:[] [] virtnet_send_command+0xf3/0x150 dpdk-guest1 kernel: RSP: 0018:ffff8800ba947a20 EFLAGS: 00000246 dpdk-guest1 kernel: RAX: 0000000000000000 RBX: ffff8800bbb0e840 RCX: ffff8801b658d000 dpdk-guest1 kernel: RDX: 000000000000c050 RSI: ffff8800ba947a24 RDI: ffff8800bbaf0c00 dpdk-guest1 kernel: RBP: ffff8800ba947ab8 R08: 0000000000000004 R09: ffff8801b9001b00 dpdk-guest1 kernel: R10: ffff8800ba676340 R11: ffff8801b76d1000 R12: 0000000000000002 dpdk-guest1 kernel: R13: ffff8800ba947a48 R14: 0000000000000000 R15: 0000000000000000 dpdk-guest1 kernel: FS: 00007f2a7a9fe700(0000) GS:ffff8801bfc80000(0000) knlGS:0000000000000000 dpdk-guest1 kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 dpdk-guest1 kernel: CR2: 00007fed60775000 CR3: 0000000001e0a000 CR4: 00000000001406e0 dpdk-guest1 kernel: Stack: dpdk-guest1 kernel: 0000000000000000 ffffea0002eec382 0000000200000940 0000000000000000 dpdk-guest1 kernel: 0000000000000000 ffffea0002eec382 0000000100000942 0000000000000000 dpdk-guest1 kernel: 0000000000000000 ffff8800ba947a28 ffff8800ba947ac8 ffff8800ba947a48 dpdk-guest1 kernel: Call Trace: dpdk-guest1 kernel: [] virtnet_set_rx_mode+0xb5/0x2f0 dpdk-guest1 kernel: [] __dev_set_rx_mode+0x3f/0x90 dpdk-guest1 kernel: [] dev_set_rx_mode+0x26/0x40 dpdk-guest1 kernel: [] dev_set_promiscuity+0x3c/0x50 dpdk-guest1 kernel: [] packet_dev_mc+0x77/0x90 dpdk-guest1 kernel: [] packet_release+0x147/0x360 dpdk-guest1 kernel: [] sock_release+0x1f/0x80 dpdk-guest1 kernel: [] sock_close+0x12/0x20 dpdk-guest1 kernel: [] __fput+0xe4/0x220 dpdk-guest1 kernel: [] ____fput+0xe/0x10 dpdk-guest1 kernel: [] task_work_run+0x73/0x90 dpdk-guest1 kernel: [] do_exit+0x2e4/0xae0 dpdk-guest1 kernel: [] do_group_exit+0x43/0xb0 dpdk-guest1 kernel: [] get_signal+0x292/0x600 dpdk-guest1 kernel: [] do_signal+0x37/0x6f0 dpdk-guest1 kernel: [] exit_to_usermode_loop+0x8c/0xd0 dpdk-guest1 kernel: [] syscall_return_slowpath+0x4e/0x60 dpdk-guest1 kernel: [] int_ret_from_sys_call+0x25/0x8f dpdk-guest1 kernel: Code: 44 89 e2 4c 89 6c c5 b0 e8 9b de ec ff 48 8b 7b 08 e8 52 de ec ff 84 c0 75 11 eb 24 48 8b 7b 08 e8 33 d9 ec ff 84 c0 75 17 f3 90 <48> 8b 7b 08 48 8d b5 6c ff ff ff e8 ad e2 ec ff 48 85 c0 74 dc Afterwards this hang continues to catch reocurring - "NMI watchdog: BUG: soft lockup" - "rcu_sched detected stalls on CPUs/tasks" The backtrace matches the former message of "device eth2 left promiscuous mode". It seems something on the path of "giving back" the device that kills it. ### More Logs ### # EAL Log so far after initialization: # dpdk-guest1 testpmd[5650]: EAL: TSC frequency is ~2397227 KHz dpdk-guest1 testpmd[5650]: EAL: WARNING: cpu flags constant_tsc=yes nonstop_tsc=no -> using unreliable clock cycles ! dpdk-guest1 testpmd[5650]: EAL: Master lcore 0 is ready (tid=dfc058c0;cpuset=[0]) dpdk-guest1 testpmd[5650]: PMD: Initializing pmd_pcap for eth_pcap0 dpdk-guest1 kernel: device eth1 entered promiscuous mode dpdk-guest1 testpmd[5650]: PMD: Creating pcap-backed ethdev on numa socket 0 dpdk-guest1 testpmd[5650]: PMD: Initializing pmd_pcap for eth_pcap1 dpdk-guest1 kernel: device eth2 entered promiscuous mode dpdk-guest1 testpmd[5650]: PMD: Creating pcap-backed ethdev on numa socket 0 dpdk-guest1 testpmd[5650]: EAL: lcore 3 is ready (tid=799fc700;cpuset=[3]) dpdk-guest1 testpmd[5650]: EAL: lcore 1 is ready (tid=7a9fe700;cpuset=[1]) dpdk-guest1 testpmd[5650]: EAL: lcore 2 is ready (tid=7a1fd700;cpuset=[2]) dpdk-guest1 testpmd[5650]: EAL: PCI device 0000:00:03.0 on NUMA socket -1 dpdk-guest1 testpmd[5650]: EAL: probe driver: 1af4:1000 rte_virtio_pmd dpdk-guest1 testpmd[5650]: EAL: Device is blacklisted, not initializing dpdk-guest1 testpmd[5650]: EAL: PCI device 0000:00:04.0 on NUMA socket -1 dpdk-guest1 testpmd[5650]: EAL: probe driver: 1af4:1000 rte_virtio_pmd dpdk-guest1 testpmd[5650]: EAL: PCI device 0000:00:05.0 on NUMA socket -1 dpdk-guest1 testpmd[5650]: EAL: probe driver: 1af4:1000 rte_virtio_pmd dpdk-guest1 testpmd[5650]: PMD: gntalloc: ioctl error => All fine, the gntalloc is no issue (avoided by the testpmd patch I submitted a while ago) # Config info from testpmd's console: # testpmd> show config cores List of forwarding lcores: 1 2 3 testpmd> show config fwd io packet forwarding - ports=4 - cores=1 - streams=4 - NUMA support disabled, MP over anonymous pages disabled Logical Core 1 (socket 0) forwards packets on 4 streams: RX P=0/Q=0 (socket 0) -> TX P=1/Q=0 (socket 0) peer=02:00:00:00:00:01 RX P=1/Q=0 (socket 0) -> TX P=0/Q=0 (socket 0) peer=02:00:00:00:00:00 RX P=2/Q=0 (socket 0) -> TX P=3/Q=0 (socket 0) peer=02:00:00:00:00:03 RX P=3/Q=0 (socket 0) -> TX P=2/Q=0 (socket 0) peer=02:00:00:00:00:02 testpmd> show port info all ********************* Infos for port 0 ********************* MAC address: 00:00:00:01:02:03 Connect to socket: 0 memory allocation on the socket: 0 Link status: up Link speed: 10000 Mbps Link duplex: full-duplex Promiscuous mode: disabled Allmulticast mode: disabled Maximum number of MAC addresses: 1 Maximum number of MAC addresses of hash filtering: 0 VLAN offload: strip on filter on qinq(extend) off No flow type is supported. Max possible RX queues: 1 Max possible number of RXDs per queue: 65535 Min possible number of RXDs per queue: 0 RXDs number alignment: 1 Max possible TX queues: 1 Max possible number of TXDs per queue: 65535 Min possible number of TXDs per queue: 0 TXDs number alignment: 1 ********************* Infos for port 1 ********************* MAC address: 00:00:00:01:02:03 Connect to socket: 0 memory allocation on the socket: 0 Link status: up Link speed: 10000 Mbps Link duplex: full-duplex Promiscuous mode: disabled Allmulticast mode: disabled Maximum number of MAC addresses: 1 Maximum number of MAC addresses of hash filtering: 0 VLAN offload: strip on filter on qinq(extend) off No flow type is supported. Max possible RX queues: 1 Max possible number of RXDs per queue: 65535 Min possible number of RXDs per queue: 0 RXDs number alignment: 1 Max possible TX queues: 1 Max possible number of TXDs per queue: 65535 Min possible number of TXDs per queue: 0 TXDs number alignment: 1 ********************* Infos for port 2 ********************* MAC address: 52:54:00:1D:22:E1 Connect to socket: 0 memory allocation on the socket: 0 Link status: up Link speed: 10000 Mbps Link duplex: full-duplex Promiscuous mode: enabled Allmulticast mode: disabled Maximum number of MAC addresses: 64 Maximum number of MAC addresses of hash filtering: 0 VLAN offload: strip on filter on qinq(extend) off No flow type is supported. Max possible RX queues: 4 Max possible number of RXDs per queue: 65535 Min possible number of RXDs per queue: 0 RXDs number alignment: 1 Max possible TX queues: 4 Max possible number of TXDs per queue: 65535 Min possible number of TXDs per queue: 0 TXDs number alignment: 1 ********************* Infos for port 3 ********************* MAC address: 52:54:00:4C:B0:4A Connect to socket: 0 memory allocation on the socket: 0 Link status: up Link speed: 10000 Mbps Link duplex: full-duplex Promiscuous mode: enabled Allmulticast mode: disabled Maximum number of MAC addresses: 64 Maximum number of MAC addresses of hash filtering: 0 VLAN offload: strip on filter on qinq(extend) off No flow type is supported. Max possible RX queues: 4 Max possible number of RXDs per queue: 65535 Min possible number of RXDs per queue: 0 RXDs number alignment: 1 Max possible TX queues: 4 Max possible number of TXDs per queue: 65535 Min possible number of TXDs per queue: 0 TXDs number alignment: 1 # Running testpmd "start tx_first" # testpmd> start tx_first io packet forwarding - CRC stripping disabled - packets/burst=32 nb forwarding cores=1 - nb forwarding ports=4 RX queues=1 - RX desc=128 - RX free threshold=0 RX threshold registers: pthresh=0 hthresh=0 wthresh=0 TX queues=1 - TX desc=512 - TX free threshold=0 TX threshold registers: pthresh=0 hthresh=0 wthresh=0 TX RS bit threshold=0 - TXQ flags=0x0 testpmd> stop Telling cores to stop... Waiting for lcores to finish... ---------------------- Forward statistics for port 0 ---------------------- RX-packets: 0 RX-dropped: 0 RX-total: 0 TX-packets: 32 TX-dropped: 0 TX-total: 32 ---------------------------------------------------------------------------- ---------------------- Forward statistics for port 1 ---------------------- RX-packets: 0 RX-dropped: 0 RX-total: 0 TX-packets: 32 TX-dropped: 0 TX-total: 32 ---------------------------------------------------------------------------- ---------------------- Forward statistics for port 2 ---------------------- RX-packets: 266 RX-dropped: 0 RX-total: 266 TX-packets: 44 TX-dropped: 0 TX-total: 44 ---------------------------------------------------------------------------- ---------------------- Forward statistics for port 3 ---------------------- RX-packets: 12 RX-dropped: 0 RX-total: 12 TX-packets: 183 TX-dropped: 115 TX-total: 298 ---------------------------------------------------------------------------- +++++++++++++++ Accumulated forward statistics for all ports+++++++++++++++ RX-packets: 278 RX-dropped: 0 RX-total: 278 TX-packets: 291 TX-dropped: 115 TX-total: 406 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Done. Christian Ehrhardt Software Engineer, Ubuntu Server Canonical Ltd