Bug 928207

Summary: transfer data using two port from guest to host,guest hang and call trace
Product: Red Hat Enterprise Linux 6 Reporter: FuXiangChun <xfu>
Component: kernelAssignee: Amit Shah <amit.shah>
Status: CLOSED ERRATA QA Contact: Virtualization Bugs <virt-bugs>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.4CC: acathrow, amit.shah, bsarathy, juzhang, lnovich, michen, mkenneth, qzhang, rhod, sradvan, virt-maint
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32-375.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-11-21 17:35:25 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description FuXiangChun 2013-03-27 07:06:27 UTC
Description of problem:
As subject, transfer data using the following small script in guest.
while true;do echo abc >/dev/vport0p1;done
while true;do echo edf >/dev/vport0p2;done

Version-Release number of selected component (if applicable):
qemu-kvm-0.12.1.2-2.358.el6.x86_64
# uname -r
2.6.32-358.5.1.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
1.Boot guest
 /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu Opteron_G3 -enable-kvm -uuid 6530dbca-555f-4212-bee9-4423ef56066d -rtc base=localtime,clock=host,driftfix=slew -m 2G -smp 2,sockets=1,cores=2,threads=1 -name rhel6.4-64 -drive file=/mnt/RHEL-Server-6.4-64-1.qcow2,format=qcow2,if=none,id=drive-ide0-0-0,werror=stop,rerror=stop,cache=none -device virtio-blk-pci,drive=drive-ide0-0-0,id=ide0-0-0 -netdev tap,id=hostnet0,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=net0,mac=04:17:21:e2:17:01,bus=pci.0,addr=0x6 -monitor stdio -usbdevice tablet -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -vnc :1 -chardev socket,id=channel1,path=/tmp/helloworld1,server,nowait -chardev socket,id=channel2,path=/tmp/helloworld2,server,nowait -serial unix:/tmp/tty0,server,nowait

2.
(qemu) device_add virtio-serial-pci,id=virtio-serial-hotadd,max_ports=16
(qemu) device_add  driver=virtserialport,chardev=channel1,name=com.redhat.rhevm.vdsm1,bus=virtio-serial-hotadd.0,id=port1
(qemu) device_add  driver=virtserialport,chardev=channel2,name=com.redhat.rhevm.vdsm1,bus=virtio-serial-hotadd.0,id=port2

3.send data from guest
#while true;do echo abc >/dev/vport0p1;done
#while true;do echo edf >/dev/vport0p2;done

4.host receive data
#nc -U /tmp/helloworld1
#nc -U /tmp/helloworld2
  
Actual results:
guest call trace

Pid: 2259, comm: bash Not tainted 2.6.32-358.5.1.el6.x86_64 #1 Red Hat KVM
RIP: 0010:[<ffffffffa007284d>]  [<ffffffffa007284d>] __send_control_msg+0x9d/0xc0 [virtio_console]
RSP: 0018:ffff88007b6f9e08  EFLAGS: 00000286
RAX: 0000000000000000 RBX: ffff88007b6f9e58 RCX: 000000000000180b
RDX: 0000000000001010 RSI: ffff88007b6f9e34 RDI: ffff88007b6f9e34
RBP: ffffffff8100bb8e R08: 0000000000000020 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000e28 R12: ffff88007b6f9df8
R13: ffffffff8100bb8e R14: ffff88007b6f9df8 R15: ffffffff8100bd6e
FS:  00007f86fb536700(0000) GS:ffff880002200000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000469680 CR3: 000000007b473000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process bash (pid: 2259, threadinfo ffff88007b6f8000, task ffff88007b756080)
Stack:
 ffffea0001b0067a 0000000800000e28 0000000000000000 0000000000000000
<d> 0000000600000002 ffff88007b075260 0000000000000000 ffff880037000c80
<d> ffff880037000ca0 ffff88007aba3d48 ffff88007b6f9e68 ffffffffa0072899
Call Trace:
 [<ffffffffa0072899>] ? send_control_msg+0x29/0x30 [virtio_console]
 [<ffffffffa0072e36>] ? port_fops_release+0x26/0x90 [virtio_console]
 [<ffffffff81182825>] ? __fput+0xf5/0x210
 [<ffffffff81182965>] ? fput+0x25/0x30
 [<ffffffff8117ddbd>] ? filp_close+0x5d/0x90
 [<ffffffff81194cd0>] ? sys_dup3+0x130/0x190
 [<ffffffff81194d44>] ? sys_dup2+0x14/0x50
 [<ffffffff8100b072>] ? system_call_fastpath+0x16/0x1b
Code: 89 e6 48 89 df e8 f4 7c fc ff 85 c0 78 ab 48 89 df 4c 8d 65 dc e8 44 78 fc ff eb 04 66 90 f3 90 4c 89 e6 48 89 df e8 73 7b fc ff <48> 85 c0 74 ee 31 c0 48 8b 5d e8 4c 8b 65 f0 4c 8b 6d f8 c9 c3



Expected results:
guest work well

Additional info:

Comment 1 Amit Shah 2013-03-28 09:49:11 UTC
I tried this on a RHEL6 host with new flow control patches and RHEL6 guest.

In the guest, I got:

virtio_console virtio0: control-o:id 0 is not a head!

In the host, I get:
qemu-kvm: virtio-serial-bus: Unexpected port id 478762112 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762112 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762112 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762112 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0
qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0

Comment 2 Amit Shah 2013-03-28 11:32:18 UTC
The out-vq of the control channel lacks locking.  Patches submitted upstream.

Comment 3 Amit Shah 2013-04-17 11:30:09 UTC
Upstream patches:

commit 165b1b8bbc17c9469b053bab78b11b7cbce6d161
Author: Amit Shah
Date:   Fri Mar 29 16:30:07 2013 +0530

    virtio: console: rename cvq_lock to c_ivq_lock
    
    The cvq_lock was taken for the c_ivq.  Rename the lock to make that
    obvious.
    
    We'll also add a lock around the c_ovq in the next commit, so there's no
    ambiguity.

commit 9ba5c80b1aea8648a3efe5f22dc1f7cacdfbeeb8
Author: Amit Shah
Date:   Fri Mar 29 16:30:08 2013 +0530

    virtio: console: add locking around c_ovq operations
    
    When multiple ovq operations are being performed (lots of open/close
    operations on virtio_console fds), the __send_control_msg() function can
    get confused without locking.
    
    A simple recipe to cause badness is:
    * create a QEMU VM with two virtio-serial ports
    * in the guest, do
      while true;do echo abc >/dev/vport0p1;done
      while true;do echo edf >/dev/vport0p2;done
    
    In one run, this caused a panic in __send_control_msg().  In another, I
    got
    
       virtio_console virtio0: control-o:id 0 is not a head!
    
    This also results repeated messages similar to these on the host:
    
      qemu-kvm: virtio-serial-bus: Unexpected port id 478762112 for device virtio-serial-bus.0
      qemu-kvm: virtio-serial-bus: Unexpected port id 478762368 for device virtio-serial-bus.0

Comment 4 RHEL Program Management 2013-04-18 10:40:58 UTC
This request was evaluated by Red Hat Product Management for
inclusion in a Red Hat Enterprise Linux release.  Product
Management has requested further review of this request by
Red Hat Engineering, for potential inclusion in a Red Hat
Enterprise Linux release for currently deployed products.
This request is not yet committed for inclusion in a release.

Comment 5 Jarod Wilson 2013-05-08 20:36:06 UTC
Patch(es) available on kernel-2.6.32-375.el6

Comment 11 FuXiangChun 2013-07-01 06:30:51 UTC
Can reproduce this issue with kernel 2.6.32-358.el6.x86_64(host and guest kernel)

Verify this issue with 2.6.32-394.el6.x86_64

according to steps in comment 0.  guest and host work well. 

so this bug is fixed.

Comment 14 errata-xmlrpc 2013-11-21 17:35:25 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2013-1645.html