Bug 1390413 - port allocator allocates the same port for multiple guests (race condition)
Summary: port allocator allocates the same port for multiple guests (race condition)
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: libvirt
Version: 25
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Libvirt Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: 1397440
TreeView+ depends on / blocked
 
Reported: 2016-11-01 02:29 UTC by David Hill
Modified: 2017-05-15 04:36 UTC (History)
24 users (show)

Fixed In Version: libvirt-2.2.1-1.fc25
Clone Of:
: 1397440 (view as bug list)
Environment:
Last Closed: 2017-05-15 04:36:43 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Logs of VMs (89.09 KB, application/x-gzip)
2016-11-06 18:05 UTC, David Hill
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Launchpad 1647229 0 None None None 2016-12-09 19:10:07 UTC

Description David Hill 2016-11-01 02:29:21 UTC
Description of problem:
Once in a while, libvirtd will fail to start a VM and retrying soon after will in the end start it properly:
Oct 31 22:24:12 zappa.orion libvirtd[31784]: Unable to read from monitor: Connection reset by peer
Oct 31 22:24:12 zappa.orion libvirtd[31784]: internal error: qemu unexpectedly closed the monitor: 
                                             (process:19455): Spice-WARNING **: reds.c:2651:reds_init_socket: reds_init_socket: binding socket to 0.0.0.0:5903 failed
                                             
                                             (process:19455): Spice-WARNING **: reds.c:3650:reds_set_video_codecs: spice: unsupported video encoder gstreamer
                                             
                                             (process:19455): Spice-WARNING **: reds.c:3650:reds_set_video_codecs: spice: unsupported video encoder gstreamer
                                             
                                             (process:19455): Spice-WARNING **: reds.c:3650:reds_set_video_codecs: spice: unsupported video encoder gstreamer
                                             2016-11-01T02:24:12.646437Z qemu-system-x86_64: failed to initialize spice server


Version-Release number of selected component (if applicable):


How reproducible:
Random

Steps to Reproduce:
1. Create 10 VMs
2. Try to start them sequentially
3.

Actual results:
Sometimes it fails

Expected results:
Always succeed

Additional info:

Comment 1 Peter Krempa 2016-11-01 04:35:09 UTC
Could you please post the tail of the VM log file including the command line for qemu. The log file is located in /var/log/libvirt/qemu/$VMNAME.log.

Looks like the port allocator code in libvirt may be experiencing a race condition, which would manifest itself by qemu not being able to listen on the selected socket as other process would grab it. This should be visible in the log file.

Additionally log files of other VMs may show that a different VM attempted to use the same socket.

Comment 2 Victor Toso 2016-11-01 13:09:53 UTC
Oh sorry. I moved it to spice by mistake. I think it is worth to wait for the info from comment #1 to say it is spice issue.

Comment 3 David Hill 2016-11-06 18:05:03 UTC
Created attachment 1217796 [details]
Logs of VMs

Comment 4 congzhangzh 2016-11-19 07:09:23 UTC
I have the same problem too!

I follow https://www.kraxel.org/blog/2016/09/using-virtio-gpu-with-libvirt-and-spice/ try to make virtio with 3d support, but always get the unsupported video encoder gstreamer problem! if I  commit the <gl enable='yes'/>, it will works again!

I use fedora 25, with nvid driver  http://www.nvidia.com/download/driverResults.aspx/111596/en-us 

tks:)

Comment 5 Christophe Fergeau 2016-11-21 09:25:47 UTC
I don't think the warning about gstreamer is going to cause problems, we should reword it to "skipping unknown gstreamer encoder", and make it an info or debug message.
'reds.c:2651:reds_init_socket: reds_init_socket: binding socket to 0.0.0.0:5903 failed' is more worrying and should not happen if libvirt is autoallocating the port to use for spice. I'd check that this port number is not hardcoded in the libvirt VM definition though.

Comment 6 Peter Krempa 2016-11-22 14:22:18 UTC
From the logs provided:

I picked a time when multiple VMs are started and listed the port for SPICE and whether startup was successful:

control-0-rhosp8.log-20161006:2016-09-28 16:24:59.620
SPICE port: 5907
startup success

ceph-1-rhosp8.log-20161007:2016-09-28 16:24:57.822
SPICE port: 5901
startup failed

ceph-2-rhosp8.log-20161007:2016-09-28 16:24:59.155
SPICE port: 5902
startup success

control-1-rhosp8.log-20161007:2016-09-28 16:25:01.175
SPICE port: 5903
startup success

compute-0-rhosp8.log-20161007:2016-09-28 16:24:59.305
SPICE port: 5902
startup failed

control-2-rhosp8.log-20161007:2016-09-28 16:25:08.553
SPICE port: 5904
startup success

ceph-0-rhosp8.log-20161006:2016-09-28 16:24:57.443
SPICE port: 5901
startup success

From the above it's clear that the port allocator code allocated the same port for multiple VMs, which made some of them fail once they actually tried to bind to the port.

Note that the following message "(process:19455): Spice-WARNING **: reds.c:3650:reds_set_video_codecs: spice: unsupported video encoder gstreamer" is not relevant to this bug.

Comment 7 David Hill 2016-11-30 15:33:07 UTC
This seems to happens more frequently when there're lots of existing VMs on the hypervisor.

Comment 8 David Hill 2016-11-30 15:34:24 UTC
I can also confirm that the port definition is not hardcoded in the VM definition.

Comment 9 Pavel Hrdina 2017-02-24 09:13:27 UTC
Upstream commit:

commit c23b7b81db58c61b0adc98095dca7bfbad74fa79
Author: Pavel Hrdina <phrdina>
Date:   Fri Feb 24 02:28:40 2017 +0100

    qemu_process: spice: don't release used port

Comment 10 Fedora Update System 2017-05-11 13:36:54 UTC
libvirt-2.2.1-1.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-4b67f65db3

Comment 11 Fedora Update System 2017-05-12 13:37:08 UTC
libvirt-2.2.1-1.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-4b67f65db3

Comment 12 Fedora Update System 2017-05-15 04:36:43 UTC
libvirt-2.2.1-1.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.