Bug 908435

This request was not resolved in time for the current release.
Red Hat invites you to ask your support representative to
propose this request, if still desired, for consideration in
the next release of Red Hat Enterprise Linux.

can you get SPICE_DEBUG=1 when this happens? thanks

I've reproduced on RHEL7 localhost migration -> ruling out any network hiccups and I am attaching debug log which is from a moment before client_migrate_info and a moment after client got disconnected from source totally.

Created attachment 823040 [details]
Spice clietn debug log

(In reply to Marian Krcmarik from comment #5)
> Created attachment 823040 [details]
> Spice clietn debug log

thanks, the log indicate quite clearly that the server sent a volume message. moving to server

reading snd_worker.c, the current set volume is sent when the channel is connected to peer. It looks like  spice_server_playback_set_volume() was called by qemu with volume at maximum...

this seems to work fine with current spice and qemu git.

(In reply to Marc-Andre Lureau from comment #8)
> this seems to work fine with current spice and qemu git.

something we didn't precise until now is which audio device is emulated. I test with HDA and it works fine, sending a single correct volume message on reconnection.

However, with AC97, there seems to be some race, where some garbage/uninitialized value is sent first before sending the migrated volume state.

Could you verify too it's AC97 only? and move the bug to qemu?

Since spice server sends currently set volume on connection, and connection happen before the migration state is restored, the client receives the initial AC97 volume set during:

#0  spice_server_playback_set_volume (sin=0x55555651b948, nchannels=2 '\002', volume=0x7fffffffcf70) at snd_worker.c:1002
#1  0x00005555555eeb7e in line_out_ctl (hw=0x55555651b8c0, cmd=3) at audio/spiceaudio.c:218
#2  0x00005555555e86da in AUD_set_volume_out (sw=0x5555564f12a0, mute=1, lvol=255 '\377', rvol=255 '\377') at audio/audio.c:2075
#3  0x0000555555680339 in update_combined_volume_out (s=0x55555650d420) at hw/audio/ac97.c:468
#4  0x000055555568043f in set_volume (s=0x55555650d420, index=2, val=32768) at hw/audio/ac97.c:488
#5  0x000055555568079c in mixer_reset (s=0x55555650d420) at hw/audio/ac97.c:548
#6  0x000055555568246e in ac97_on_reset (opaque=0x55555650d420) at hw/audio/ac97.c:1339
#7  0x0000555555869785 in qemu_devices_reset () at vl.c:1836
#8  0x00005555558697f1 in qemu_system_reset (report=false) at vl.c:1845
#9  0x0000555555871227 in main (argc=35, argv=0x7fffffffd5f8, envp=0x7fffffffd718) at vl.c:4340

Created attachment 823152 [details]
rfc patch

patch proposed:
 
    RFC: ac97: don't set audio backend volume during migration
    
    The volume will be restored and set in post load.  This avoids an
    audible volume glitch during migration with AC97. It may be better to
    move this check in the audio layer, since it should be guaranteed to
    have volume restored on migration.

sorry for late reply

(In reply to Marc-Andre Lureau from comment #9)
> (In reply to Marc-Andre Lureau from comment #8)
> > this seems to work fine with current spice and qemu git.
> 
> something we didn't precise until now is which audio device is emulated. I
> test with HDA and it works fine, sending a single correct volume message on
> reconnection.
> 
> However, with AC97, there seems to be some race, where some
> garbage/uninitialized value is sent first before sending the migrated volume
> state.
> 
> Could you verify too it's AC97 only? and move the bug to qemu?

I don't hear any significand difference between ich6 and ac97 (same guest, same client, just different soundcard, largely unused 1GbE network, time synced, client just few ms from host). The glitch may be worse with ac97 but that may be just I can't tell that reliably.
What I get more consistently with ich6 is a brief pause on _start_ of the migration (mentioned in the email).

anyway, what is the purpose of the volume message? It seems to cause bug 1012868 (happens when your client volume is lower than guest volume - client volume gets synced to guest volume on migration). This happens regardless of qemu soundcard as well.

(In reply to David Jaša from comment #12)
> sorry for late reply
> 
> (In reply to Marc-Andre Lureau from comment #9)
> > (In reply to Marc-Andre Lureau from comment #8)
> > > this seems to work fine with current spice and qemu git.
> > 
> > something we didn't precise until now is which audio device is emulated. I
> > test with HDA and it works fine, sending a single correct volume message on
> > reconnection.
> > 
> > However, with AC97, there seems to be some race, where some
> > garbage/uninitialized value is sent first before sending the migrated volume
> > state.
> > 
> > Could you verify too it's AC97 only? and move the bug to qemu?
> 
> I don't hear any significand difference between ich6 and ac97 (same guest,
> same client, just different soundcard, largely unused 1GbE network, time
> synced, client just few ms from host). The glitch may be worse with ac97 but
> that may be just I can't tell that reliably.
> What I get more consistently with ich6 is a brief pause on _start_ of the
> migration (mentioned in the email).
> 
> anyway, what is the purpose of the volume message? It seems to cause bug

During migration? it shouldn't be needed.

> 1012868 (happens when your client volume is lower than guest volume - client
> volume gets synced to guest volume on migration). This happens regardless of
> qemu soundcard as well.

Client volume is drived by guest volume (so you can get full volume range, avoid multiple volume knobs, be a good desktop audio citizen). However, there is a caveat that could explain this bug, if the stream volume is changed in the client, this is not reflected in the guest. We would need some extra agent messages to sync in both directions.

QE,
We will not fix it in RHEL6. Please test on RHEL7, and if it reproduces, move this BZ to RHEL7. Otherwise we will close it.
Thanks.

(In reply to Ronen Hod from comment #14)
> QE,
> We will not fix it in RHEL6. Please test on RHEL7, and if it reproduces,
> move this BZ to RHEL7. Otherwise we will close it.
> Thanks.

Hi, Ronen

Get it. 

Hi, Maosheng

Could you give a hand to test it on a RHEL7 host?


Thanks,
Qunfang

Hit this problem on rhel7 host.

Host & Client:
qemu-img-rhev-1.5.3-57.el7ev.x86_64
libvirt-daemon-driver-qemu-1.1.1-27.el7.x86_64
ipxe-roms-qemu-20130517-5.gitc4bce43.el7.noarch
qemu-kvm-rhev-debuginfo-1.5.3-57.el7ev.x86_64
qemu-kvm-tools-rhev-1.5.3-57.el7ev.x86_64
qemu-kvm-rhev-1.5.3-57.el7ev.x86_64
qemu-guest-agent-1.5.3-53.el7.x86_64
qemu-kvm-common-rhev-1.5.3-57.el7ev.x86_64
spice-vdagent-0.14.0-7.el7.x86_64
spice-gtk3-0.20-8.el7.x86_64
spice-glib-0.20-8.el7.x86_64
spice-server-0.12.4-5.el7.x86_64
virt-viewer-0.5.7-7.el7.x86_64

Guest:
RHEL6.5
kernel-2.6.32-451.el6.x86_64

Steps:
1. Boot vm with sound device.
/usr/libexec/qemu-kvm \
-M pc \
-cpu SandyBridge \
-m 4G \
-smp 4,sockets=2,cores=2,threads=1,maxcpus=160 \
-enable-kvm \
-name rhel7-64 \
-uuid 990ea161-6b67-47b2-b803-19fb01d30d12 \
-smbios type=1,manufacturer='Red Hat',product='RHEV Hypervisor',version=el6,serial=koTUXQrb,uuid=feebc8fd-f8b0-4e75-abc3-e63fcdb67170 \
-k en-us \
-rtc base=localtime,clock=host,driftfix=slew \
-nodefaults \
-monitor stdio \
-qmp tcp:0:6666,server,nowait \
-boot menu=on \
-bios /usr/share/seabios/bios.bin \
-monitor unix:/tmp/guest-sock,server,nowait \
-drive file=/home/rhel6.6-64.qcow2,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop,aio=threads \
-device virtio-blk-pci,scsi=off,bus=pci.0,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1,addr=0x8 \
-vga qxl \
-spice port=5900,disable-ticketing,seamless-migration=on \
-netdev tap,id=hostnet0,vhost=on \
-device virtio-net-pci,netdev=hostnet0,id=net0,mac=52:54:00:39:13:2c \
-device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 \
-device usb-tablet,id=input0 \
-device intel-hda,id=sound0,bus=pci.0,addr=0x9 \
-device hda-duplex \

2. Start qemu-kvm instance on remote host with "-incoming tcp:0:5800"

3. Do migration
(qemu) client_migrate_info spice 10.66.4.217 5900
(qemu) migrate -d tcp:10.66.4.217:5800

Result:
Heard the crack in end of migration, at the same time hmp output below messages:
(qemu) red_client_migrate: migrate client with #channels 6
red_dispatcher_display_migrate: channel type 2 id 0
red_dispatcher_cursor_migrate: channel type 4 id 0

(In reply to Ronen Hod from comment #14)
> QE,
> We will not fix it in RHEL6. Please test on RHEL7, and if it reproduces,
> move this BZ to RHEL7. Otherwise we will close it.
> Thanks.

Hello, Ronen

QE just tested this bug in comment 16. And if you won't plan to fix it in RHEL6, I'd suggest to close it as WONTFIX and then clone a new one in RHEL7 component. Please do not move it directly to RHEL7 in case our QE hit it again in RHEL6 and file new bug in future.  Is this okay for you? 

Thanks,
Qunfang

File a new bug 1081795 on RHEL7 against this problem.

(In reply to Qunfang Zhang from comment #17)
> Hello, Ronen
> 
> QE just tested this bug in comment 16. And if you won't plan to fix it in
> RHEL6, I'd suggest to close it as WONTFIX and then clone a new one in RHEL7
> component. Please do not move it directly to RHEL7 in case our QE hit it
> again in RHEL6 and file new bug in future.  Is this okay for you? 
> 
> Thanks,
> Qunfang

Thanks, Ronen.